Vscode-cpptools: cpptools extension takes 100% CPU always on Linux..

[nbellari]

As soon as the editor starts and I open a C file, the extension Microsoft.VSCode.CPP.Extension.Linux takes 100% CPU and never comes down. Because of this, navigating through symbols in various files has become slow - it takes ~5 seconds for each symbol navigation.

Is there anything that can be done to mitigate this issue?

Operating System: Ubuntu 14.04, kernel: 4.4.0-119-generic
VS Code version: 1.22.2
cpptools version: 0.16.1
No other c/c++ related extensions installed - even after removing the other extensions (like beautify, python etc.) the issue still persists
No logging information available after changing the log level to "Information"

[bobbrow]

It sounds like the IntelliSense server might be stuck in an infinite loop. Are you able to share the code that causes this problem?

[bobbrow]

or attach a debugger and share the callstack.

[nbellari]

Hi,

Apologies, I cannot send you the code/file which is being opened, however, here is the backtrace and the strace output on the process. I will be happy to provide any other information that you need.

(gdb) bt
#0  0x00007f98f491937d in read () at ../sysdeps/unix/syscall-template.S:81
#1  0x00007f98f48a45b0 in _IO_new_file_underflow (fp=0x7f98f4bed640 <_IO_2_1_stdin_>) at fileops.c:613
#2  0x00007f98f48a553e in __GI__IO_default_uflow (fp=0x7f98f4bed640 <_IO_2_1_stdin_>) at genops.c:435
#3  0x00007f98f489bace in _IO_getc (fp=0x7f98f4bed640 <_IO_2_1_stdin_>) at getc.c:39
#4  0x0000000000b15725 in std::__1::__stdinbuf<char>::__getchar(bool) ()
#5  0x00000000005fde79 in std::__1::basic_istream<char, std::__1::char_traits<char> >& std::__1::getline<char, std::__1::char_traits<char>, std::__1::allocator<char> >(std::__1::basic_istream<char, std::__1::char_traits<char> >&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >&, char) ()
#6  0x00000000005b2533 in vscode::message_handler::main_loop() ()
#7  0x000000000061d21c in main ()
(gdb) info threads
  Id   Target Id         Frame 
  13   Thread 0x7f98f4207700 (LWP 3958) "Microsoft.VSCod" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  12   Thread 0x7f98f3a06700 (LWP 3959) "Microsoft.VSCod" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  11   Thread 0x7f98f3205700 (LWP 3960) "Microsoft.VSCod" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  10   Thread 0x7f98f2a04700 (LWP 3961) "Microsoft.VSCod" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  9    Thread 0x7f98f2203700 (LWP 3962) "Microsoft.VSCod" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  8    Thread 0x7f98f1a02700 (LWP 3963) "Microsoft.VSCod" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  7    Thread 0x7f98f1201700 (LWP 3964) "Microsoft.VSCod" 0x00007f98f4c023ad in read () at ../sysdeps/unix/syscall-template.S:81
  6    Thread 0x7f98f0a00700 (LWP 3965) "Microsoft.VSCod" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  5    Thread 0x7f98d3fff700 (LWP 3966) "Microsoft.VSCod" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  4    Thread 0x7f98d37fe700 (LWP 3967) "Microsoft.VSCod" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  3    Thread 0x7f98d2ffd700 (LWP 4158) "Microsoft.VSCod" pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  2    Thread 0x7f98d237a700 (LWP 4179) "Microsoft.VSCod" 0x00007f98f4c023ad in read () at ../sysdeps/unix/syscall-template.S:81
* 1    Thread 0x7f98f530c740 (LWP 3957) "Microsoft.VSCod" 0x00007f98f491937d in read () at ../sysdeps/unix/syscall-template.S:81
(gdb) 

[-] sudo strace -p 3957
Process 3957 attached
read(0, "Content-Length: 53\r\n\r\n{\"jsonrpc\""..., 4096) = 75
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n{\"jsonrpc\""..., 4096) = 75
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 196\r\n\r\n{\"jsonrpc"..., 4096) = 219
futex(0x7ffecce1ce6c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1ce68, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n", 4096) = 22
read(0, "{\"jsonrpc\":\"2.0\",\"method\":\"cppto"..., 4096) = 53
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n", 4096) = 22
read(0, "{\"jsonrpc\":\"2.0\",\"method\":\"cppto"..., 4096) = 53
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n{\"jsonrpc\""..., 4096) = 75
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n{\"jsonrpc\""..., 4096) = 75
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n", 4096) = 22
read(0, "{\"jsonrpc\":\"2.0\",\"method\":\"cppto"..., 4096) = 53
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n{\"jsonrpc\""..., 4096) = 75
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n", 4096) = 22
read(0, "{\"jsonrpc\":\"2.0\",\"method\":\"cppto"..., 4096) = 53
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n", 4096) = 22
read(0, "{\"jsonrpc\":\"2.0\",\"method\":\"cppto"..., 4096) = 53
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n", 4096) = 22
read(0, "{\"jsonrpc\":\"2.0\",\"method\":\"cppto"..., 4096) = 53
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n{\"jsonrpc\""..., 4096) = 75
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 197\r\n\r\n", 4096) = 23
read(0, "{\"jsonrpc\":\"2.0\",\"id\":7,\"method\""..., 4096) = 197
futex(0x7ffecce1ce6c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1ce68, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, "Content-Length: 53\r\n\r\n", 4096) = 22
read(0, "{\"jsonrpc\":\"2.0\",\"method\":\"cppto"..., 4096) = 53
futex(0x7ffecce1d13c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7ffecce1d138, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
read(0, ^CProcess 3957 detached

[nbellari]

A question: Does it build and cache the index for the scanned files? Or does it build the index afresh every time the editor is opened?

[bobbrow]

We save the timestamp of the files we index, so if they haven't changed since the last scan, we won't reparse them the next time the editor is opened.

[bobbrow]

Are you able to get the call stacks from the other threads? The main thread's callstack is not very interesting. It's just waiting for messages from the extension.

[bobbrow]

Oh, wait a minute. I misread your original comment. This is not an infinite loop in the IntelliSense server. This is probably just heavy processing when you open a new folder. Do you see the database icon in the bottom right corner of the status bar? You can reduce the CPU usage of the indexing by using the "C_Cpp.workspaceParsingPriority" setting.

[nbellari]

I see, thanks for the setting. I see that after sometime (a very long time), the CPU utilization is indeed coming down - probably because I have a very large includePath to scan.

Thanks!

[Spongman]

I'm seeing the same issue. On linux, it takes > 5 minutes of CPU time (more real time) to settle down. until then it's unusable.

Id: ms-vscode.cpptools
Version: 0.27.0

[seokbeomKim]

Same issue on Ubuntu WSL. I think this issue should be reopened.

1. CPU Usage:
   

2. strace to cpptools
   

3. strace to cpptools_srv
   

4. O/S
   workspace/study/linux master ✔ 20d9h ▶ uname -a Linux DESKTOP-D9CRKT8 4.19.84-microsoft-standard #1 SMP Wed Nov 13 11:44:37 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

5. code/extension version info:

6. C:\Users\sukbeom>code --version 1.44.2 ff915844119ce9485abfe8aa9076ec76b5300ddd x64

• .vscode-server/extensions/ms-vscode.cpptools-0.28.0-insiders

[Colengms]

@seokbeomKim . Could you enable logging for the cpptools extension using "C_Cpp.loggingLevel": "Debug", and let us know if there is activity in the log while there is CPU load? Or, the log output leading up to the issue? It is by-design that the cpptools process would be busy while tag parser.

[seokbeomKim]

@Colengms After I've just waited few minutes after opening a file, the issue has been gone. Sorry for making you confused.