Extension randomly gets stuck communicating with the IntelliSense process on Mac

[bvschaik]

Issue Type: Bug

I'm working with a fairly large C codebase (~75k lines of code), and the plugin stops working at random.

When it does:

• Code completion is not available
• File outline is not available
• Checking for errors/warnings stops working
• Quick fixes and function documentation remain on "loading..."
• Sometimes, CPU usage for the C/C++ plugin process goes up and remains high until I kill VSCode

Unfortunately it stops working rather randomly, so I am unable to pinpoint what exactly is causing it. Sometimes it works for hours without problems, sometimes it stops 5 minutes after opening the project. If it stops, it stops for all windows and all tabs. Restarting VSCode is the only solution I found so far.

If there's anything I can do to try and debug this, please let me know.

OS: macOS Mojave. It happens on both my MacBook at work and my older MacBook at home
Compiler: clang

Extension version: 0.26.3
VS Code version: Code 1.42.1 (c47d83b293181d9be64f27ff093689e8e7aed054, 2020-02-11T14:44:27.652Z)
OS version: Darwin x64 18.7.0

System Info

Item	Value
CPUs	Intel(R) Core(TM) i7-6700HQ CPU @ 2.60GHz (8 x 2600)
GPU Status	2d_canvas: enabled flash_3d: enabled flash_stage3d: enabled flash_stage3d_baseline: enabled gpu_compositing: enabled metal: disabled_off multiple_raster_threads: enabled_on oop_rasterization: disabled_off protected_video_decode: unavailable_off rasterization: enabled skia_renderer: disabled_off surface_control: disabled_off surface_synchronization: enabled_on video_decode: enabled viz_display_compositor: enabled_on viz_hit_test_surface_layer: disabled_off webgl: enabled webgl2: enabled
Load (avg)	2, 2, 2
Memory (System)	16.00GB (0.70GB free)
Process Argv	-psn_0_6186470
Screen Reader	no
VM	0%

[michelleangela]

@bvschaik, you can enable logging for the language server to get info on what the server is processing at the time when IntelliSense features are not working.

In addition to the language server logs, can you also provide the following info:

• When opening the project on VSCode, are there files already opened? If so about how many files?
• What happens when there is no file or only one file open at the start of VSCode?
• Do you have more than one or more projects (or multiroot) in a workspace? If so, are you switching between the two or more projects when the issue occurs?

[bvschaik]

@michelleangela I've enabled debug logging, if it happens again I will post the log.

Regarding your other questions:

When opening the project on VSCode, are there files already opened? If so about how many files?
What happens when there is no file or only one file open at the start of VSCode?

It differs. Sometimes I have none, sometimes a couple of dozen. Since I didn't pay attention to the number of open files when starting VSCode, I don't know what happens if there are none or 1 open at the start. I'll try to keep track of that.

Do you have more than one or more projects (or multiroot) in a workspace? If so, are you switching between the two or more projects when the issue occurs?

No, I just have the one project/directory open. Sometimes I have a second window with another (smaller) C project open though. It happens really randomly. Sometimes I'm typing code and halfway a variable name the language service stops and I end up with an error in the editor "variable XY does not exist" that won't go away until a restart, even though "XY" has already been completed to a valid variable name.

[michelleangela]

@bvschaik thanks for providing more info. Since a consistent repro steps have not been determined yet, we'll need the logs to further see what's happening when the issue occurs. Perhaps the logs will show some consistent processing behavior when the issue occurs.

[bvschaik]

@michelleangela Funny, after enabling logging it has not happened again, but I haven't done very much development work. I'll continue monitoring this and will post logs once it locks up again.

[bvschaik]

@michelleangela I finally got a lock-up today. It suddenly stopped while I was editing a line to reverse two bitwise operators. Last few lines of the log:

Checking for syntax errors: file:///Users/bianca/projects/julius/src/graphics/screenshot.c
Queueing IntelliSense update for files in translation unit of: /Users/bianca/projects/julius/src/graphics/screenshot.c
cpptools/getCodeActions: 322
textDocument/didChange
cpptools/textEditorSelectionChange
sending 10 changes to server
textDocument/didChange
cpptools/textEditorSelectionChange
completionItem/resolve: 323
sending 1 changes to server
Checking for syntax errors: file:///Users/bianca/projects/julius/src/graphics/screenshot.c
Queueing IntelliSense update for files in translation unit of: /Users/bianca/projects/julius/src/graphics/screenshot.c
  tag parsing file: /Users/bianca/projects/julius/src/graphics/screenshot.c

No errors or anything, the log just stopped here. Hovering over items, etc does not add anything more to the log. At the moment it stopped I had 8 .c files and 2 .h files open, two of the .c files were unsaved.

Complete log: full_log.zip

In Output -> Log (Extension Host) I found the following errors, but I think they're just by-products of the extension stopping, not the cause:

[2020-02-27 11:06:11.574] [exthost] [error] onWillSaveTextDocument-listener from extension 'ms-vscode.cpptools' threw ERROR
[2020-02-27 11:06:11.645] [exthost] [error] Error: timeout
	at Timeout._onTimeout (/Users/bianca/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/services/extensions/node/extensionHostProcess.js:494:345)
	at listOnTimeout (internal/timers.js:531:17)
	at processTimers (internal/timers.js:475:7)
[2020-02-27 11:13:01.860] [exthost] [error] onWillSaveTextDocument-listener from extension 'ms-vscode.cpptools' threw ERROR
[2020-02-27 11:13:01.860] [exthost] [error] Error: timeout
	at Timeout._onTimeout (/Users/bianca/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/services/extensions/node/extensionHostProcess.js:494:345)
	at listOnTimeout (internal/timers.js:531:17)
	at processTimers (internal/timers.js:475:7)
[2020-02-27 11:13:03.991] [exthost] [error] onWillSaveTextDocument-listener from extension 'ms-vscode.cpptools' threw ERROR
[2020-02-27 11:13:03.991] [exthost] [error] Error: timeout
	at Timeout._onTimeout (/Users/bianca/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/services/extensions/node/extensionHostProcess.js:494:345)
	at listOnTimeout (internal/timers.js:531:17)
	at processTimers (internal/timers.js:475:7)
[2020-02-27 11:13:09.116] [exthost] [error] onWillSaveTextDocument-listener from extension 'ms-vscode.cpptools' threw ERROR
[2020-02-27 11:13:09.116] [exthost] [error] Error: timeout
	at Timeout._onTimeout (/Users/bianca/Applications/Visual Studio Code.app/Contents/Resources/app/out/vs/workbench/services/extensions/node/extensionHostProcess.js:494:345)
	at listOnTimeout (internal/timers.js:531:17)
	at processTimers (internal/timers.js:475:7)

[sean-mcmanus]

It sounds like our main process is stuck perhaps in a deadlock. When it gets stuck, does killing the Microsoft.VSCode.CPP.IntelliSense.darwin process cause it to start working again? Are you able to attach to the processes to get a call stack of where the threads are stuck (threads that are doing work and not just waiting). We're planning to release an insiders update on Monday with lots of changes, but it seems unlikely that we fixed this issue.

[bvschaik]

I sampled the stuck process in Activity Monitor, which results in call stacks for every thread (most of which are waiting): Sample of Microsoft.VSCode.CPP.Extension.darwin.txt
List of open files for the process: open_files.txt

If I kill it, everything indeed starts working again, with a large number of errors like these in Output -> cpptools:

[Error - 6:50:16 AM] Connection to server got closed. Server will not be restarted.
[Error - 6:50:16 AM] Request completionItem/resolve failed.
Error: Connection got disposed.
	at Object.dispose (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:3191:25)
	at Object.dispose (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:3552:35)
	at LanguageClient.handleConnectionClosed (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:5634:42)
	at LanguageClient.handleConnectionClosed (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:15423:15)
	at closeHandler (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:5621:18)
	at CallbackList.invoke (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:10457:39)
	at Emitter.fire (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:10515:36)
	at closeHandler (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:2541:26)
	at CallbackList.invoke (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:10457:39)
	at Emitter.fire (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:10515:36)
	at StreamMessageReader.fireClose (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:13290:27)
	at Socket.<anonymous> (/Users/bianca/.vscode/extensions/ms-vscode.cpptools-0.26.3/dist/main.js:13330:46)
	at Socket.emit (events.js:205:15)
	at Pipe.<anonymous> (net.js:586:12)

[sean-mcmanus]

Thanks a lot for the tracing logs. You appear to be hitting the same issue we've been recently seeing in our automated tests on Mac in which communication to the IntelliSense process gets randomly stuck (our build lab repros it, but we haven't gotten local repros yet). We started noticing this regression after our Mac's machines updated to XCode/Clang 11, which suggests that an OS change may be to blame (our code dealing with this hasn't changed, and we haven't seen any repros on Linux or Windows).

Is the Microsoft.VSCode.CPP.IntelliSense.Msvc.darwin process running? Are you able to get call stacks of that process?

[bvschaik]

Is the Microsoft.VSCode.CPP.IntelliSense.Msvc.darwin process running? Are you able to get call stacks of that process?

You mean during such a lock-up? I'm not sure, the Macbook on which the extension got stuck yesterday has been rebooted, so it's in a clean state now and has not yet locked up.

Looking at the processes: I have one Microsoft.VSCode.CPP.Extension.darwin process, and two Microsoft.VSCode.CPP.IntelliSense.Msvc.darwin processes. On my personal Macbook, I currently have three Microsoft.VSCode.CPP.Extension.darwin processes and five(!) Microsoft.VSCode.CPP.IntelliSense.Msvc.darwin processes. Is it normal to have multiple of them running?

By the way, this lock up has been happening to me for at least 1.5 month, since that's when I started using VSCode for development. I don't remember exactly, but I think I installed Xcode 11 in October/November already.

[sean-mcmanus]

Yes, there should be 1 "IntelliSense" process per open file up to a core limit. If you close files and wait several seconds, then the processes should close. Doing a Find All References or Rename can also spawn temporary IntelliSense processes.

[sean-mcmanus]

I got a repro on Mac (via doing Find All References on std::string in the LLVM project) -- it randomly got stuck.

[sean-mcmanus]

This is fixed with https://github.com/microsoft/vscode-cpptools/releases/tag/0.27.0-insiders3

[bvschaik]

Thanks! I'm using the insiders version, and so far I've not had any lockups, though I've not done too much coding yet.