Microsoft.VSCode.CPP.IntelliSense.Msvc.linux at 100% CPU for hours

[eskild]

(I already posted this in another bug, but was kindly asked to file it differently. I hope this is good; it's my first report re. vscode.)

Ubuntu 14.04. VSCode 1.17.1. C++ extension 0.13.1. Disabling other extensions doesn't seem to affect problem.

I work with a source tree of around 1500 files of mixed C/C++.

Problem: ~/.vscode/extensions/ms-vscode.cpptools-0.13.1/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux runs at 100% continuously, and IntelliSense barely works.

I've now resorted to a small script that'll kill all such processes. Then it'll run and IntelliSense will be usable for a few minutes, and then we're back at 100%

I finally got annoyed enough to attach gdb to the offending thread and got this trace; maybe it inspires some ideas. It smells like endless looping, perhaps due to wrong error handling in file I/O. I've frequently seen code that doesn't get error handling entirely right when, for example, a file disappears under its feet and where it just keeps looping, trying to read from a file that no longer provides data. Particularly with sub-processes.

In my usecase I compile frequently, and part of our build process generates new C++ files that are then compiled into the final images. I wouldn't be surprised if VSCode got surprised about this "flapping" of files.

All the other threads sit seemingly idle in futex waits. Some of them probably waiting for this one.

#0  0x000000000073b3f9 in source_file_for_seq ()
#1  0x000000000089982d in an_error_ptr_cmp::operator()(an_error* const&, an_error* const&) const ()
#2  0x000000000089ae52 in an_error_manager::get_errors(std::__1::vector<an_error*, std::__1::allocator<an_error*> >&) ()
#3  0x000000000053c6bd in edge::scoped_query_manager::get_filtered_errors_for_tu(edge::list<edge::error*>*, bool (*)(edge::error const&)) ()
#4  0x000000000054484d in edge::an_edge_translation_unit_impl::get_filtered_errors_for_tu(edge::allocator*, edge::snapshot_session const*, bool (*)(edge::error const&), edge::isense_error_array*) ()
#5  0x000000000050c2f0 in edge_intellisense_server_impl::handle_get_errors(microsoft::cpp::intellisense::GetErrorsRequest const&) ()
#6  0x0000000000530c0d in work_queue::worker_proc() ()
#7  0x000000000052d323 in std::__1::__function::__func<microsoft::vc::thread_pool::enqueue(std::__1::function<void ()>, std::__1::future<void>*)::{lambda()#1}, std::__1::allocator<{lambda()#1}>, void ()>::operator()() ()
#8  0x00000000008bddbd in microsoft::vc::thread_pool::thread_pool(int)::{lambda()#1}::operator()() const ()
#9  0x00000000008bdbad in void* std::__1::__thread_proxy<std::__1::tuple<microsoft::vc::thread_pool::thread_pool(int)::{lambda()#1}> >(std::__1::tuple<microsoft::vc::thread_pool::thread_pool(int)::{lambda()#1}>) ()
#10 0x00007f058bdcc184 in start_thread (arg=0x7f0583fff700) at pthread_create.c:312
#11 0x00007f058baf1ffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

[ihalip]

Happens to me too, and I think only 0.13.1 has this issue.

[bobbrow]

We have gotten reports of crashes at that call site, but nothing we've been able to reproduce in our offices. Do you or any of the "thumbs up" responders have an open source project, or small repro that we can use to investigate this?

If the CPU is at 100% forever, then it is likely an infinite loop somewhere in the IntelliSense engine, not a crash though. The only loops in this particular call stack involve an error list that is capped at 1000 entries by default. If you grabbed this call stack shortly after opening or editing a file, it could still be in the process of reporting the error squiggles which is normal behavior. If you leave the VS Code editor alone for a while and grab the call stack again, do you get the same thing?

[eskild]

My stack was taken once, after more than 17 hours of CPU time. Didn’t take it again after that. Will try to get more data.

…

Den 19. okt. 2017 kl. 22.06 skrev Bob Brown ***@***.***>: We have gotten reports of crashes at that call site, but nothing we've been able to reproduce in our offices. Do you or any of the "thumbs up" responders have an open source project, or small repro that we can use to investigate this? If the CPU is at 100% forever, then it is likely an infinite loop somewhere in the IntelliSense engine, not a crash though. The only loops in this particular call stack involve an error list that is capped at 1000 entries by default. If you grabbed this call stack shortly after opening or editing a file, it could still be in the process of reporting the error squiggles which is normal behavior. If you leave the VS Code editor alone for a while and grab the call stack again, do you get the same thing? — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or mute the thread.

[eskild]

One thing, maybe, is that our source tree uses symlinking from one tree to another, and Code/CPP does tend to get a bit confused about that sometimes. (Please note that there is no symlink recursion.)

   repo1_dir
      ...many files and dirs...
   repo2_dir
      symlink to ../repo1_dir
      ...many files and dirs...

[sean-mcmanus]

@eskild Your call stack with source_file_for_seq matches a crash we're seeing (somewhere around our 3rd highest hitting crash), but it doesn't directly contain any loops, so I'm not sure how the crash and the infinite processing are connected.

[liyichao]

In mac, Version 0.14.0，cpu is also 100%，it is 100% since some versions, but I can not remember which:

[eskild]

Status update: I've been running 0.14.0 with VSCode 1.17.2 for a couple days now, and so far the problem I reported has not shown itself. With a little luck, it may have been fixed by the indexer work for 0.14.0.

I'll leave this issue open for a few days, and then close it if all remains well.

[ihalip]

I'm also running vscode 1.17.2 with ms-vscode.cpptools 0.14.0 and I still see the same issue.

Right now, I'm working in a directory with ~8000 source files and ~9000 headers and I see 2 Microsoft.VSCode.CPP.Extension.linux processes taking 100% CPU. Seems like most of the work is being done in a thread that parses files and stores info in an sqlite database.

[bobbrow]

@ihalip, there should only be one instance of Microsoft.VSCode.CPP.Extension.linux running if you only have one instance of VS Code running. Can you close VS Code, kill the lingering processes and try again? I wonder if the old 0.13.1 process didn't get shut down during the update.

[ihalip]

That didn't seem to help. The same thread is completely hogging 1 CPU core.

[eskild]

@ihalip You could try and enable logging to see if the indexing progresses. From the cpptools release note:

Add logging to Output window. Errors will be logged by default. Verbosity is controlled by the "C_Cpp.loggingLevel" setting.

I use "C_Cpp.loggingLevel": "Information"; it provides some amount of progress info, even if it isn't a) terribly detailed and b) time-stamped (@bobbrow, would be useful :-)

It's fair enough that the extension spends some time, maybe a few minutes, busily working, but when we get into two-digit minutes, something starts to smell suspect for common project sizes. Even NetBeans is quicker, then...

[sean-mcmanus]

@ihalip 1 minute of high CPU usage on 1 thread is not an indication of a bug. We need to know what it says on the tooltip on the database icon in the bottom right or if there's some error in the files that are being processed (as seen via the logging).
@eskild Long parse times can occur if it tries to recursively parse all the system headers.

[ihalip]

I enabled the logging and let the process run for some time while I monitored the Output window. It did finish after about a while (around 15 minutes IIRC) and indexed about 59000 files, after which CPU usage dropped completely - so it looks like my issue was only due to the project size. I also have a number of paths added to c_cpp_properties.json which might slow it down.

[eskild]

Status update: Still no runaway CPU usage on 0.14.0, so that's great.

@bobbrow I do have a left-behind process containing a small bunch of threads.

$ ps -auxw | grep vscode
uid  11848  0.4  1.6 2534172 267980 ?      Sl   Oct23  27:03 /home/uid/.vscode/extensions/ms-vscode.cpptools-0.14.0/bin/Microsoft.VSCode.CPP.Extension.linux

$ sudo strace -p 11848 -f
Process 11848 attached with 12 threads
[pid 29852] open("/tmp/pipe_server_request_11848_72", O_RDONLY|O_CLOEXEC <unfinished ...>
[pid 21413] open("/tmp/pipe_server_request_11848_36", O_RDONLY|O_CLOEXEC <unfinished ...>
[pid 11877] futex(0x7f590a7fc9d0, FUTEX_WAIT, 29852, NULL <unfinished ...>
[pid 11856] futex(0x7f5881884efc, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
[pid 11855] futex(0x7f58adf3c15c, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
[pid 11853] futex(0x7f59100f7d7c, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
[pid 11854] futex(0x7f58deffd9d0, FUTEX_WAIT, 21413, NULL <unfinished ...>
[pid 11852] futex(0x7f591405173c, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
[pid 11851] futex(0x7f592400187c, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
[pid 11850] futex(0x7f591f29211c, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
[pid 11849] futex(0x7f590c000a1c, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
[pid 11848] futex(0x7f5922ffd9d0, FUTEX_WAIT, 11877, NULL^CProcess 11848 detached

$ ls -l /tmp/pipe_server_request_11848_*
prwx------ 1 uid gid 0 Oct 23 10:47 /tmp/pipe_server_request_11848_36
prwx------ 1 uid gid 0 Oct 24 14:25 /tmp/pipe_server_request_11848_72

So, the problem I originally reported appears to be fixed, but this lingering process is an indication that all isn't entirely well yet. Please advise whether I should close this bug and create a new one?

[bobbrow]

I'll see if I can find the other issue where I talked about this. You can close this one.

[eskild]

Right-o. Closing.

[eskild]

Reopening, sorry about that. VSCode 1.18.0, cpptools 0.14.2: Runaway process, same place.

$ ps auxw | grep VSCode.CPP
...
me    992  0.0  0.6 901196 209740 ?       Sl   Nov16   0:02 /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux 31328 1
me   1020  0.0  0.5 1568156 176840 ?      Sl   Nov16   1:17 /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.Extension.linux
me   1054  0.0  0.0 761640 13348 ?        Sl   Nov16   0:00 /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux 1020 1
me  13021  0.0  0.0 761644 27888 ?        Sl   Nov16   0:00 /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux 31328 5
me  19527  0.0  0.3 827308 117756 ?       Sl   Nov16   0:00 /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux 31328 12

me  19617 99.7  0.3 827048 113092 ?       Sl   Nov16 1102:48 /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux 31328 13

me  30684  0.0  0.0 761512 13184 ?        Sl   Nov16   0:00 /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux 1020 3
me  30885  0.0  0.0 761512 18820 ?        Sl   Nov16   0:00 /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux 1020 4
me  31328  0.3  1.0 1955520 354032 ?      Sl   Nov16   4:26 /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.Extension.linux
me  31384  0.0  0.0 761644 25268 ?        Sl   Nov16   0:00 /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux 31328 0

Trying with GDB:

$ sudo gdb /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux -p 19619
...
Reading symbols from /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux...(no debugging symbols found)...done.

Is there a way to get a symbol table? Maybe I could get at the local variables for you?

Attaching to program: /home/me/.vscode/extensions/ms-vscode.cpptools-0.14.2/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.linux, process 19619
...
0x00000000007401d2 in source_file_for_seq ()
(gdb) where
#0  0x00000000007401d2 in source_file_for_seq ()
#1  0x00000000008a6b5d in an_error_ptr_cmp::operator()(an_error* const&, an_error* const&) const ()
#2  0x00000000008a7c09 in an_error_manager::get_errors(std::__1::vector<an_error*, std::__1::allocator<an_error*> >&) ()
#3  0x000000000053ebbd in edge::scoped_query_manager::get_filtered_errors_for_tu(edge::list<edge::error*>*, bool (*)(edge::error const&)) ()
#4  0x0000000000546ccd in edge::an_edge_translation_unit_impl::get_filtered_errors_for_tu(edge::allocator*, edge::snapshot_session const*, bool (*)(edge::error const&), edge::isense_error_array*) ()
#5  0x000000000050d6f0 in edge_intellisense_server_impl::handle_get_errors(microsoft::cpp::intellisense::GetErrorsRequest const&) ()
#6  0x00000000005330dd in work_queue::worker_proc() ()
#7  0x000000000052eab3 in std::__1::__function::__func<microsoft::vc::thread_pool::enqueue(std::__1::function<void ()>, std::__1::future<void>*)::{lambda()#1}, std::__1::allocator<{lambda()#1}>, void ()>::operator()() ()
#8  0x00000000008ca9dd in microsoft::vc::thread_pool::thread_pool(int)::{lambda()#1}::operator()() const ()
#9  0x00000000008ca7cd in void* std::__1::__thread_proxy<std::__1::tuple<microsoft::vc::thread_pool::thread_pool(int)::{lambda()#1}> >(std::__1::tuple<microsoft::vc::thread_pool::thread_pool(int)::{lambda()#1}>) ()
#10 0x00007fdf997a6184 in start_thread (arg=0x7fdf98da5700) at pthread_create.c:312
#11 0x00007fdf994cbffd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Ok, let's try to single-step to see if we're stuck in that func:

(gdb) next
Single stepping until exit from function source_file_for_seq,
which has no line number information.

(A minute or so passes)

^CQuit
(gdb) 

So it appears we're stuck. I also tried 'strace' on the thread, but no system call activity was reported. I'd say the evidence points to an endless loop.

[deepskyblue86]

Same here. Visual Studio Code (linux)

Version 1.19.2
Commit 490ef761b76b3f3b3832eff7a588aac891e5fe80
Date 2018-01-10T15:57:21.071Z
Shell 1.7.9
Renderer 58.0.3029.110
Node 7.9.0
Architecture x64

Backtrace:

#0  0x00000000007407b2 in source_file_for_seq ()
#1  0x00000000008a713d in an_error_ptr_cmp::operator()(an_error* const&, an_error* const&) const ()
#2  0x00000000008a81e9 in an_error_manager::get_errors(std::__1::vector<an_error*, std::__1::allocator<an_error*> >&) ()
#3  0x000000000053f19d in edge::scoped_query_manager::get_filtered_errors_for_tu(edge::list<edge::error*>*, bool (*)(edge::error const&)) ()
#4  0x00000000005472ad in edge::an_edge_translation_unit_impl::get_filtered_errors_for_tu(edge::allocator*, edge::snapshot_session const*, bool (*)(edge::error const&), edge::isense_error_array*) ()
#5  0x000000000050dc90 in edge_intellisense_server_impl::handle_get_errors(microsoft::cpp::intellisense::GetErrorsRequest const&) ()
#6  0x00000000005336bd in work_queue::worker_proc() ()
#7  0x000000000052f093 in std::__1::__function::__func<microsoft::vc::thread_pool::enqueue(std::__1::function<void ()>, std::__1::future<void>*)::{lambda()#1}, std::__1::allocator<{lambda()#1}>, void ()>::operator()() ()
#8  0x00000000008cb35d in microsoft::vc::thread_pool::thread_pool(int)::{lambda()#1}::operator()() const ()
#9  0x00000000008cb14d in void* std::__1::__thread_proxy<std::__1::tuple<microsoft::vc::thread_pool::thread_pool(int)::{lambda()#1}> >(std::__1::tuple<microsoft::vc::thread_pool::thread_pool(int)::{lambda()#1}>) ()
#10 0x00007f9d2bee46ba in start_thread (arg=0x7f9d2a4ee700) at pthread_create.c:333
#11 0x00007f9d2bc1a41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109```

It seems really similar to https://bugs.kde.org/show_bug.cgi?id=386720
If both are using clang, it may be exactly the same.

[sean-mcmanus]

@deepskyblue86 This is caused by a difficult to track down and repro memory corruption that has existed since we introduced the IntelliSense process in April/0.11.0 (#1337). Do you have a repro we can use? I may have a repro with internal code, but I don't know yet.

[sean-mcmanus]

@deepskyblue86 I found a repro for a crash that I believe has the same root cause (corrupted il_header).

[sean-mcmanus]

From what I've seen so far, this "source_file_for_seq" crash only occurs if headers can't be found and/or there are too many errors (i.e. due to missing headers), so one potential work around is to make sure the includePaths can be found by IntelliSense. However, we still want to fix this crash, since it's our highest hitter, and we have a repro internally (the fixed corrupted il_header bug I mentioned previously turned out to be a different crash).

[sean-mcmanus]

@deepskyblue86 @eskild Changing line
"--exceptions",
to
"--exceptions", "--error_limit", "2147483647",
in msvc.json in the bin folder of the cpptools extension should fix the crash, although it's possible we might come up with a better fix later. If the crash still occurs after this change, that would mean our parsing is failing for another reason and we'd have to do a better fix.

[eskild]

@sean-mcmanus Sounds good, thank you. I really hope it goes away now; I've added the params to msvc.json, and then we'll see.

Please forgive me for saying this, because I haven't done the debugging and therefore I'm ignorant, but doesn't this smell a bit more of workaround than fix? I mean, given sufficiently "hostile" input, we might end up with the problem manifesting itself again. Or?

[bobbrow]

It's not easy for us to determine if the IntelliSense engine is stuck in an infinite loop or legitimately taking a long time, but we are considering adding logic to terminate and disable it if the QoS is sufficiently bad for a given code file. I think it would be safe to say that if parsing or IntelliSense operations take more than ## seconds/minutes each, then the engine is not serving you in any meaningful way and we should probably use the fuzzy IntelliSense for that file instead.

[sean-mcmanus]

@eskild Yeah, it's a workaround to avoid the crash. If we see this is still a problem, we'll investigate fixing the root cause (error limit aborting causes a data structure to be missing expected data, leading to a crash). The buggy code is "owned" by another team in VS so maybe they'll fix the root issue later. It sounds like @bobbrow is talking about a different issue (intelliSense getting stuck).

[eskild]

@sean-mcmanus Thanks for elaborating, appreciate it! 👍

[sean-mcmanus]

You can try a preview .vsix at https://github.com/Microsoft/vscode-cpptools/releases/tag/v0.15.0-insiders (our final release is planned for next week). We suspect it will solve most of the crashes, but the root cause of the crash when the error limit is exceeded is still being investigated by another team (it repros in VS 2017 too).

[eskild]

Cool, installed .vsix. I noticed that the --error-limit is set at 25000, so I'll leave it there as opposed to the earlier suggestion of 2^31. Will keep you posted if I encounter anything.

[sean-mcmanus]

Yeah, we lowered the error limit to avoid the possibility of an infinite loop of error processing. The previous limit was only 250.

[eskild]

Hm... I'm seeing runaway CPU on macos right now, 1.20.1, cpptools-0.15.0-insiders.

I'm on a somewhat slow, but stable, VPN from home, and was just shutting down vscode for the day.

I have several left-over processes, and one run-away from the first startup of vscode earlier today. The other ones appear to come from subsequent startups.

me 77002  99.7  0.0  4307212   2724   ??  R    10:00AM 302:03.41 /Users/me/.vscode/extensions/ms-vscode.cpptools-0.15.0-insiders/bin/Microsoft.VSCode.CPP.IntelliSense.Msvc.darwin 76846 4
me 87325   0.0  0.1  4315232  13204   ??  S     4:55PM   0:00.30 /Users/me/.vscode/extensions/ms-vscode.cpptools-0.15.0-insiders/bin/Microsoft.VSCode.CPP.Extension.darwin
me 87236   0.0  0.1  4315040  13488   ??  S     4:52PM   0:00.35 /Users/me/.vscode/extensions/ms-vscode.cpptools-0.15.0-insiders/bin/Microsoft.VSCode.CPP.Extension.darwin
me 78596   0.0  0.0  4315040  11484   ??  S    12:04PM   0:00.34 /Users/me/.vscode/extensions/ms-vscode.cpptools-0.15.0-insiders/bin/Microsoft.VSCode.CPP.Extension.darwin

I tried attaching lldb, but I'm really not an expert in debugging on macos, so... But here it is:

(lldb) bt
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x00007fff531b18be libsystem_kernel.dylib`swtch_pri + 10
    frame #1: 0x00007fff532f7307 libsystem_pthread.dylib`sched_yield + 11
    frame #2: 0x00000001024ceefe Microsoft.VSCode.CPP.IntelliSense.Msvc.darwin`intellisense_server_base::shutdown() + 62
    frame #3: 0x00000001024cb820 Microsoft.VSCode.CPP.IntelliSense.Msvc.darwin`edge_intellisense_server_impl::~edge_intellisense_server_impl() + 32
    frame #4: 0x00000001024cb7f9 Microsoft.VSCode.CPP.IntelliSense.Msvc.darwin`edge_intellisense_server_impl::~edge_intellisense_server_impl() + 9
    frame #5: 0x00000001024cb7c3 Microsoft.VSCode.CPP.IntelliSense.Msvc.darwin`std::__1::__shared_ptr_pointer<edge_intellisense_server_impl*, std::__1::default_delete<edge_intellisense_server_impl>, std::__1::allocator<edge_intellisense_server_impl> >::__on_zero_shared() + 19
    frame #6: 0x00007fff510d38fd libc++.1.dylib`std::__1::__shared_weak_count::__release_shared() + 43
    frame #7: 0x00000001024cbb8f Microsoft.VSCode.CPP.IntelliSense.Msvc.darwin`main + 351
    frame #8: 0x00007fff5306b115 libdyld.dylib`start + 1

Sorry I can't be more helpful, but it appears we're not entirely home free yet.

[sean-mcmanus]

Our main process will kill the IntelliSense process when it's shutdown, but it's possible our main process may have crashed beforehand. The IntelliSense process is stuck waiting for another thread to shutdown -- we've added code that aborts the waiting if it takes too long. Are you able to get call stacks for the dangling main processes? I've witnessed some random dangling main processes and crashes on Mac too so we'll try do more investigation on Mac for March.

[sean-mcmanus]

@eskild @ihalip @deepskyblue86 0.15.0 fixed the source_file_for_seq crash (at least for most scenarios, an additional fix for remaining scenarios may occur later). The dangling IntelliSense processes should be reduced as well. Can you file a new bug for any additional crashes or dangling processes? We've seen some remaining cases happening randomly that we'll continue to investigate later.

[deepskyblue86]

@sean-mcmanus I'm using the 0.15.0 preview since when you asked us to try it. I'm happy with it, no issue at all. I'll try the official release today!