Processing a large compile_commands.json takes too long

[akbyrd]

Environment

• OS and Version: Win10 22H2 19045
• VS Code Version: 1.94
• C/C++ Extension Version: 1.21.6
• If using SSH remote, specify OS of remote machine: N/A

Bug Summary and Steps to Reproduce

Bug Summary: The extension gets stuck initializing Intellisense more or less permanently when loading a compilation database with a large number of file entries. The extension is unusable while this occurs. It's a single threaded process that appears to process every file in the compilation database before enabling any LSP features for currently opened files.

Steps to reproduce:

1. Clone UnrealEngine (use a shallow clone to make it faster)
   a. Sorry, I know this is a pain for a repro. There's a small, self-contained partial repro I can't share publicly if there's a private channel available.
2. Open the folder with vscode
3. Run GenerateProjectFiles.bat -VSCode
4. Close and re-open vscode (still as a folder, you don't need to use the workspace)
5. Open a file (e.g. AssertionMacroTests.cpp)
6. Notice Intellisense is initializing
7. Wait a while
8. Notice Intellisense is still initializing
9. Attempt to "go to definition" on a #include statement
10. Notice no code navigation or code completion operations work

Expected behavior:

• Intellisense and LSP operations for the currently active file are prioritized above all other files.
• Beginning normal LSP operations is not blocked on doing any operation on every single file in the directory.

When not using compile commands the tag parser fallback behaves correctly. It will immediately parse the current open file. Similarly, clangd handles the current file before doing background indexing.

It's also possible to observe the bad behavior with just the .vscode directory and not the entire engine. When the actual code files are missing the C/C++ Configuration Warnings output will be spammed with errors like this:

[10/9/2024, 9:37:04 AM] Unable to locate forced include: D:\UnrealEngine\Engine\Intermediate\Build\Win64\x64\UnrealEditorGPF\Development\UnrealEd\SharedPCH.UnrealEd.Cpp20.h

While this is occurring, Intellisense is in the "initializing" state indicating that it is processing every single file in the database before the init completes and LSP operations in the current file begin to function.

Configuration and Logs

{
    "configurations": [
        {
            "name": "Win32",
            "compilerPath": "C:\\Program Files\\Microsoft Visual Studio\\2022\\Professional\\VC\\Tools\\MSVC\\14.38.33130\\bin\\Hostx64\\x64\\cl.exe",
            "cStandard": "c17",
            "cppStandard": "c++20",
            "intelliSenseMode": "msvc-x64",
            "compileCommands": "D:\\UnrealEngine\\.vscode\\compileCommands_Default.json"
        }
    ],
    "version": 4
}

I don't think I can get C/C++: Log Diagnostics. The command doesn't do anything. Looks like it's an LSP request? And since the LSP is essentially stalled it's not returning a response.

loggingLevel: Debug
LSP: (received) cpptools/initialize (id: 1)
LSP: (invoked) cpptools/initialize (id: 1)
cpptools version (TypeScript): 1.21.6
cpptools version (native): 1.21.6.0
Autocomplete is enabled.
Error squiggles are enabled.
Hover is enabled.
IntelliSense Engine = default.
LSP: Sending response (id: 1)
LSP: (received) cpptools/queryCompilerDefaults (id: 2)
LSP: (invoked) cpptools/queryCompilerDefaults (id: 2)
LSP: Sending response (id: 2)
LSP: (received) cpptools/didChangeCppProperties (id: 3)
LSP: (invoked) cpptools/didChangeCppProperties (id: 3)
LSP: (received) cpptools/didChangeSettings
LSP: (received) cpptools/didChangeSettings
LSP: (received) cpptools/didChangeSettings
LSP: (received - deferred) textDocument/didOpen: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp
LSP: Message ignored due to no registered handler: $/setTrace
LSP: (received - deferred) cpptools/didChangeVisibleTextEditors
LSP: (received - deferred) cpptools/didChangeVisibleTextEditors
LSP: (received - deferred) cpptools/didChangeVisibleTextEditors
LSP: (received - deferred) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 4)
LSP: (received - deferred) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 5)
LSP: (received - deferred) cpptools/getFoldingRanges: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 6)
LSP: (received) cpptools/didChangeSettings
LSP: (received - deferred) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 7)
LSP: (received - deferred) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 8)
LSP: $/cancelRequest (cpptools/getCodeActions, id: 4)
LSP: $/cancelRequest (cpptools/getCodeActions, id: 5)
LSP: $/cancelRequest (cpptools/getFoldingRanges, id: 6)
LSP: $/cancelRequest (cpptools/getCodeActions, id: 7)
LSP: (received - deferred) cpptools/getDocumentSymbols: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 9)
Code browsing service initialized
Attempting to get defaults from C++ compiler in "compilerPath" property: 'C:\Program Files\Microsoft Visual Studio\2022\Professional\VC\Tools\MSVC\14.38.33130\bin\Hostx64\x64\cl.exe'
Attempting to get defaults from C compiler in "compilerPath" property: 'C:\Program Files\Microsoft Visual Studio\2022\Professional\VC\Tools\MSVC\14.38.33130\bin\Hostx64\x64\cl.exe'

Other Extensions

I've repro'd on Insiders with no other extensions.

Additional context

No response

[sean-mcmanus]

@akbyrd Did you repro this with 1.22.8 too? That has some potential fixes.

It appears to be stuck from (invoked) cpptools/didChangeCppProperties

[akbyrd]

Yea, looks like the insiders version I have is 1.22.8 and I was able to repro there. The logging is a little different though. I see a continuous stream of

Attempting to get defaults from C++ compiler in "compilerPath" property: 'C:\Program Files\Microsoft Visual Studio\2022\Professional\VC\Tools\MSVC\14.38.33130\bin\Hostx64\x64\cl.exe'

It doesn't seem stalled, it just seems like it's doing a boatload of work before enabling LSP operations.

loggingLevel: Debug
LSP: (received) cpptools/initialize (id: 1)
LSP: (invoked) cpptools/initialize (id: 1)
cpptools version (TypeScript): 1.22.8
cpptools version (native): 1.22.8.0
Autocomplete is enabled.
Error squiggles are enabled if all header dependencies are resolved.
Hover is enabled.
IntelliSense Engine = default.
LSP: Sending response (id: 1)
LSP: (received) cpptools/queryCompilerDefaults (id: 2)
LSP: (invoked) cpptools/queryCompilerDefaults (id: 2)
Compiler info database not connected - skipping load.
Compiler info database not connected - skipping load.
LSP: Sending response (id: 2)
LSP: (received) cpptools/didChangeCppProperties (id: 3)
LSP: (invoked) cpptools/didChangeCppProperties (id: 3)
LSP: (received) cpptools/didChangeSettings
LSP: (received) cpptools/didChangeSettings
LSP: (received) cpptools/didChangeSettings
LSP: (received) cpptools/didChangeSettings
LSP: (received) cpptools/didChangeSettings
LSP: (received - deferred) textDocument/didOpen: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp
LSP: (received - deferred) cpptools/didChangeVisibleTextEditors
LSP: (received - deferred) cpptools/didChangeVisibleTextEditors
LSP: (received - deferred) cpptools/didChangeVisibleTextEditors
LSP: (received - deferred) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 4)
LSP: (received - deferred) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 5)
LSP: (received - deferred) cpptools/getFoldingRanges: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 6)
LSP: (received - deferred) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 7)
LSP: $/cancelRequest (cpptools/getCodeActions, id: 4)
LSP: $/cancelRequest (cpptools/getCodeActions, id: 5)
LSP: $/cancelRequest (cpptools/getFoldingRanges, id: 6)
LSP: Message ignored due to no registered handler: $/setTrace
LSP: (received) cpptools/didChangeSettings
LSP: (received - deferred) cpptools/getDocumentSymbols: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 8)
LSP: $/cancelRequest (cpptools/getCodeActions, id: 7)
LSP: (received - deferred) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 9)
LSP: (received - deferred) cpptools/getDocumentSymbols: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 10)
Code browsing service initialized
Populating file name cache...
Done populating filename cache. Elapsed time: 0 ms
Attempting to get defaults from C compiler in "compilerPath" property: 'C:\Program Files\Microsoft Visual Studio\2022\Professional\VC\Tools\MSVC\14.38.33130\bin\Hostx64\x64\cl.exe'
Attempting to get defaults from C++ compiler in "compilerPath" property: 'C:\Program Files\Microsoft Visual Studio\2022\Professional\VC\Tools\MSVC\14.38.33130\bin\Hostx64\x64\cl.exe'
Attempting to get defaults from C++ compiler in "compilerPath" property: 'C:\Program Files\Microsoft Visual Studio\2022\Professional\VC\Tools\MSVC\14.38.33130\bin\Hostx64\x64\cl.exe'
Attempting to get defaults from C++ compiler in "compilerPath" property: 'C:\Program Files\Microsoft Visual Studio\2022\Professional\VC\Tools\MSVC\14.38.33130\bin\Hostx64\x64\cl.exe'
...

[sean-mcmanus]

@akbyrd Yeah, I think it's processing the compile_commands command. This was improved with #10029. How many compile commands entries are there? How long are you seeing it take to finish processing that?

[akbyrd]

77,727 in one workspace with just the engine
108,140 in another with the projects I need to work in

Big numbers, and I'll be the first to complain about it, but it is what it is. I can't really pare it down since I'm poking at foundational bits that everything uses.

I think the important requirement here is that Intellisense and LSP operations for the current file can't depend on work being performed in all files, only its actual dependencies. That might still be a large number of files, and that's ok, as long as it's not artificially gated by everything.

I don't think this was always an issue. I've been working in this codebase for a few years and I think the extension would fallback to the tag parser if Intellisense was still trying to catch up. I vaguely recall that I'd have basic operations that weren't entirely accurate for a while in a new workspace, then it would catch up after a while. Currently I get no operations at all, everything stalls with a loading bar until the init phase is complete.

How long are you seeing it take to finish processing that?

I haven't seen it finish yet. I'll let it go overnight tonight to see if it completes. How can I see the progress? Is there a log file with progress and timestamps so I can estimate the completion time if it doesn't finish?

[akbyrd]

After letting it sit for a while it did get past initializing. Without timestamps I can't say how long it took, but more than 1 hour and less than 2.75 hours.

I set the logging to "7" instead of "Debug" which I saw you mention elsewhere. I see about 100,000

LSP: Sending server -> client notification: cpptools/updateTrustedCompilersList

then a few

Folder: D:\BLAH\ will be indexed

then all the pending LSP operations finally begin to process

LSP: (queued) textDocument/didOpen: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp
LSP: (queued) cpptools/didChangeVisibleTextEditors
LSP: (queued) cpptools/didChangeVisibleTextEditors
LSP: (queued) cpptools/didChangeVisibleTextEditors
LSP: (queued) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 4)
LSP: (queued) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 5)
LSP: (queued) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 6)
LSP: (queued) cpptools/getDocumentSymbols: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 7)
LSP: (queued) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 8)
LSP: (queued) cpptools/getFoldingRanges: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 9)
LSP: (queued) cpptools/getDocumentSymbols: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 10)
LSP: (invoked) cpptools/getDocumentSymbols: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 7)
LSP: Sending response (id: 3)
LSP: (invoked) cpptools/getDocumentSymbols: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 10)
LSP: Sending server -> client notification: cpptools/reportStatus
LSP: Sending server -> client notification: cpptools/reportTagParseStatus
LSP: Sending server -> client notification: cpptools/reportStatus
Discovering files...
LSP: (invoked) cpptools/didChangeSettings
LSP: Sending server -> client notification: cpptools/reportStatus
Autocomplete is enabled.
Error squiggles are enabled.
Hover is enabled.
IntelliSense Engine = default.
Enhanced Colorization is enabled.
LSP: Sending server -> client notification: cpptools/reportStatus
LSP: (invoked) cpptools/didChangeSettings
Autocomplete is enabled.
Error squiggles are enabled.
Hover is enabled.
IntelliSense Engine = default.
Enhanced Colorization is enabled.
LSP: Sending server -> client notification: cpptools/reportStatus
LSP: (invoked) cpptools/didChangeSettings
Autocomplete is enabled.
Error squiggles are enabled.
Hover is enabled.
IntelliSense Engine = default.
tag parsing file: D:\UnrealEngine\Engine\Source\Runtime\Core\Tests\Misc\AssertionMacrosTest.cpp
Enhanced Colorization is enabled.
LSP: Sending server -> client notification: cpptools/reportStatus
LSP: (invoked) cpptools/didChangeSettings
Autocomplete is enabled.
Error squiggles are enabled.
Hover is enabled.
IntelliSense Engine = default.
Enhanced Colorization is enabled.
LSP: Sending server -> client notification: cpptools/reportStatus
LSP: (invoked) cpptools/queryCompilerDefaults (id: 11)
LSP: Sending response (id: 11)
LSP: (invoked) textDocument/didOpen: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp
  Processing folder (non-recursive): C:\PROGRAM FILES (X86)\MICROSOFT VISUAL STUDIO\2019\PROFESSIONAL\VC\TOOLS\MSVC\14.29.30133\INCLUDE
process_path: C:\PROGRAM FILES (X86)\MICROSOFT VISUAL STUDIO\2019\PROFESSIONAL\VC\TOOLS\MSVC\14.29.30133\INCLUDE
LSP: (invoked) cpptools/didChangeVisibleTextEditors
LSP: Sending server -> client notification: cpptools/IntelliSenseSetup
CodeSearch (prefix phase): Time(2ms) ResultsCount(6) Indexed(t) Fuzzy(f) SingleFile (t) Scoped(f) ExcludedImplicit(f)
CodeSearch: TotalResultsCount(6) TotalTime(2ms)
  Processing folder (recursive): C:\PROGRAM FILES (X86)\WINDOWS KITS\10\INCLUDE\10.0.26100.0\CPPWINRT\
process_path: C:\PROGRAM FILES (X86)\WINDOWS KITS\10\INCLUDE\10.0.26100.0\CPPWINRT\
CodeSearch: LoadResultsTime(14ms)
CodeSearch: QuerySymbolsTotalTime(17ms)
LSP: Sending response (id: 7)
CodeSearch (prefix phase): Time(1ms) ResultsCount(6) Indexed(t) Fuzzy(f) SingleFile (t) Scoped(f) ExcludedImplicit(f)
CodeSearch: TotalResultsCount(6) TotalTime(1ms)
CodeSearch: LoadResultsTime(7ms)
CodeSearch: QuerySymbolsTotalTime(9ms)
LSP: Sending response (id: 10)
tag parsing file: D:\UnrealEngine\Engine\Source\Runtime\Core\Tests\Misc\AssertionMacrosTest.cpp
Intellisense update pending for: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp
LSP: Sending server -> client notification: cpptools/reportStatus
LSP: (invoked) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 4)
LSP: (invoked) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 5)
LSP: (invoked) cpptools/getCodeActions: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (id: 6)

then some more processing

Populating file name cache...
  Processing folder (recursive): C:\PROGRAM FILES (X86)\WINDOWS KITS\10\INCLUDE\10.0.26100.0\UCRT\

Done populating filename cache. Elapsed time: 812 ms
    Memory usage delta: 142 MB
    Number of files: 6589
    Number of parent/child relationships: 5854
sending compilation args for D:\UnrealEngine\Engine\Source\Runtime\Core\Tests\Misc\AssertionMacrosTest.cpp
  include: D:\UNREALENGINE\ENGINE\SOURCE
...
  system include: C:\PROGRAM FILES\MICROSOFT VISUAL STUDIO\2022\PROFESSIONAL\VC\TOOLS\MSVC\14.38.33130\INCLUDE
...
  preinclude: D:\UNREALENGINE\ENGINE\INTERMEDIATE\BUILD\WIN64\X64\ACEXEPARSERGPF\DEVELOPMENT\CORE\DEFINITIONS.H
  stdver: ms_c++20
  intelliSenseMode: windows-msvc-x64
IntelliSense TU acquired for: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp
Starting IntelliSense update for: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp (needs_reparse==true)
Processing partial IntelliSense update for: file:///d%3A/UnrealEngine/Engine/Source/Runtime/Core/Tests/Misc/AssertionMacrosTest.cpp [0-850]
LSP: Sending server -> client notification: cpptools/reportTagParseStatus

  Discovering files: 313511 file(s) processed
  0 file(s) removed from database
LSP: Sending server -> client notification: cpptools/logTelemetry
Done discovering files.
LSP: Sending server -> client notification: cpptools/reportStatus
Parsing open files...
LSP: Sending server -> client notification: cpptools/reportStatus
Populating include completion cache.
Parsing remaining files...
tag parsing file: D:\UnrealEngine\Engine\Source\Runtime\Core\Public\Misc\AssertionMacros.h
...

[sean-mcmanus]

@akbyrd Was the 100k updateTrustedCompilersList with 1.22.8? That was supposed to be fixed by #12078 .

I think we only tested performance for a 10k compile_commands and 70-110k might require additional optimization or algorithm changes.