Got stuck at Creating completion session with arguments with full cpu usage

[htfy96]

Hi! I am using cquery with LanguageClient-Neovim. However it seems that cquery got stuck after Creating completion session with arguments, occupying half of my cores while reporting progress as {"indexRequestCount":0,"doIdMapCount":0,"loadPreviousIndexCount":0,"onIdMappedCount":0,"onIndexedCount":0}.

Debug logs from LanguageClient-Neovim:

14:10:22 DEBUG   [MainThread] => {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"file:///home/lz/code/c10k-server/a.cpp","version":5},"contentChanges":[{"text":"#include <iostream>\n\nint main()\n{\n\tstd::cin.\n}\n"}]}}
14:10:22 DEBUG   [MainThread] => {"jsonrpc":"2.0","id":5,"method":"textDocument/completion","params":{"textDocument":{"uri":"file:///home/lz/code/c10k-server/a.cpp"},"position":{"line":4,"character":10}}}
14:10:22 DEBUG   [RPC-cpp   ] <= {"jsonrpc":"2.0","method":"$cquery/progress","params":{"indexRequestCount":0,"doIdMapCount":0,"loadPreviousIndexCount":0,"onIdMappedCount":0,"onIndexedCount":0}}
14:10:22 WARNING [RPC-cpp   ] no handler implemented for $cquery_progress
14:10:22 DEBUG   [RPC-cpp   ] <= {"jsonrpc":"2.0","method":"$cquery/progress","params":{"indexRequestCount":0,"doIdMapCount":0,"loadPreviousIndexCount":0,"onIdMappedCount":0,"onIndexedCount":0}}
14:10:22 WARNING [RPC-cpp   ] no handler implemented for $cquery_progress
14:10:22 DEBUG   [RPC-cpp   ] <= {"jsonrpc":"2.0","method":"$cquery/progress","params":{"indexRequestCount":0,"doIdMapCount":0,"loadPreviousIndexCount":0,"onIdMappedCount":0,"onIndexedCount":0}}
14:10:22 WARNING [RPC-cpp   ] no handler implemented for $cquery_progress
# No completion result received after 5 minutes

I tried to debug it and found threads occupying 100% CPU were all running std::string::_S_construct. GDB log is attached at https://gist.github.com/htfy96/61969e3939b69f9e3320e25ad63b5794, and here is
LanguageServer.log.
I was just wondering is this a bug or the expected behavior?

[jacobdufault]

This feels like a bug to me. Can you try testing on a small project and see if it still happens with neovim?

Also, feel free to comment out EmitProgress in command_line.cc to remove the "$cquery/progress" messages.

[htfy96]

@jacobdufault Actually, I tried it on my toy project https://github.com/htfy96/c10k-server with clang_args as follows:

-xc++
-std=c++14
-Isrc/
-Ivendor/Catch/include
-Ivendor/spdlog/include

More information could be found at autozimu/LanguageClient-neovim#181

[MaskRay]

Let me give more input.

Dead lock may happen for trivial config like https://gist.github.com/anonymous/6e6cf05d934bd90dd27f2cd3051c84f4

One "indexer*" thread

llvm::RegisterTarget<(llvm::Triple::ArchType)18, false>::getArchMatch(llvm::Triple::ArchType) () 

It prepends an element to the singly-linked list:

  T.Next = FirstTarget;
  FirstTarget = &T;

Another "indexer*" thread and the "completeparse" thread

llvm::TargetRegistry::lookupTarget(std::string const&, std::string&) () 

const Target *TargetRegistry::lookupTarget(const std::string &TT,
                                           std::string &Error) {
..............
  auto J = std::find_if(std::next(I), targets().end(), ArchMatch);   ////////////
  if (J != targets().end()) {
    Error = std::string("Cannot choose between targets \"") + I->Name +
            "\" and \"" + J->Name + "\"";
    return nullptr;
  }

  return &*I;
}

std::next(I) is std::next(&TheX86_64Target) which points to itself (because of some race condition, its Next pointer points to itself)

(gdb) x/xg 0x7f030b2408a0         
0x7f030b2408a0 <_ZZN4llvm18getTheX86_64TargetEvE15TheX86_64Target>:     0x00007f030b2408a0 

Stack trace of one of spawned clang threads by current indexer threads, `

Thread 45 (Thread 0x7f501effd700 (LWP 35108)):
#0  0x00007f50de4d7fa0 in llvm::TargetRegistry::lookupTarget(std::string const&, std::string&) ()
   from ~/Dev/Util/cquery/build/clang+llvm-5.0.0-linux-x86_64-ubuntu14.04/lib/libclang.so.5
#1  0x00007f50debdf3cb in clang::driver::ToolChain::getTargetAndModeFromProgramName(llvm::StringRef) ()
   from ~/Dev/Util/cquery/build/clang+llvm-5.0.0-linux-x86_64-ubuntu14.04/lib/libclang.so.5
#2  0x00007f50debba90e in clang::driver::Driver::ParseDriverMode(llvm::StringRef, llvm::ArrayRef<char const*>) ()
   from ~/Dev/Util/cquery/build/clang+llvm-5.0.0-linux-x86_64-ubuntu14.04/lib/libclang.so.5
#3  0x00007f50debbe907 in clang::driver::Driver::BuildCompilation(llvm::ArrayRef<char const*>) ()
   from ~/Dev/Util/cquery/build/clang+llvm-5.0.0-linux-x86_64-ubuntu14.04/lib/libclang.so.5
#4  0x00007f50dd3b768e in clang::createInvocationFromCommandLine(llvm::ArrayRef<char const*>, llvm::IntrusiveRefCntPtr<clang::DiagnosticsEngine>, llvm::IntrusiveRefCntPtr<clang::vfs::FileSystem>) ()
   from ~/Dev/Util/cquery/build/clang+llvm-5.0.0-linux-x86_64-ubuntu14.04/lib/libclang.so.5
#5  0x00007f50dd359983 in clang::ASTUnit::LoadFromCommandLine(char const**, char const**, std::shared_ptr<clang::PCHContainerOperations>, llvm::IntrusiveRefCntPtr<clang::DiagnosticsEngine>, llvm::StringRef, bool, bool, llvm::ArrayRef<std::pair<std::string, llvm::MemoryBuffer*> >, bool, unsigned int, clang::TranslationUnitKind, bool, bool, bool, bool, bool, bool, bool, llvm::Optional<llvm::StringRef>, std::unique_ptr<clang::ASTUnit, std::default_delete<clang::ASTUnit> >*, llvm::IntrusiveRefCntPtr<clang::vfs::FileSystem>) ()
   from ~/Dev/Util/cquery/build/clang+llvm-5.0.0-linux-x86_64-ubuntu14.04/lib/libclang.so.5
#6  0x00007f50dd1202f1 in void llvm::function_ref<void ()>::callback_fn<clang_parseTranslationUnit2FullArgv::$_1>(long) ()
   from ~/Dev/Util/cquery/build/clang+llvm-5.0.0-linux-x86_64-ubuntu14.04/lib/libclang.so.5
#7  0x00007f50de4910b0 in llvm::CrashRecoveryContext::RunSafely(llvm::function_ref<void ()>) ()
   from ~/Dev/Util/cquery/build/clang+llvm-5.0.0-linux-x86_64-ubuntu14.04/lib/libclang.so.5
#8  0x00007f50de491164 in RunSafelyOnThread_Dispatch(void*) ()
   from ~/Dev/Util/cquery/build/clang+llvm-5.0.0-linux-x86_64-ubuntu14.04/lib/libclang.so.5
#9  0x00007f50de4d83ea in ExecuteOnThread_Dispatch(void*) ()
   from ~/Dev/Util/cquery/build/clang+llvm-5.0.0-linux-x86_64-ubuntu14.04/lib/libclang.so.5
#10 0x00007f50e0947494 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#11 0x00007f50dc161a8f in clone () from /lib/x86_64-linux-gnu/libc.so.6

The conclusion is that clang_parseTranslationUnit2FullArgv is not safe to call concurrently.

  CXErrorCode error_code = clang_parseTranslationUnit2FullArgv(
      index->cx_index, filepath.c_str(), args.data(), (int)args.size(),
      unsaved_files.data(), (unsigned)unsaved_files.size(), flags, &cx_tu);

[jacobdufault]

Assuming clang_parseTranslationUnit2FullArgv can never be called concurrently I'm fine with serializing requests to it. It may be that we need to move all index jobs to a separate process - I'd like to avoid doing that though (that is how cquery used to be implemented, but it seemed to work well enough in-process, and in-process avoids a lot of extra complication).

[MaskRay]

One possible mitigation is to partially serialize indexer tasks, guaranteeing that the time different threads calling clang_parseTranslationUnit2FullArgv differs by at least, say 100ms.

[MaskRay]

If on-disk storage will ever be added to cquery, multi-process poses more problems because IPC is difficult and many embedded database does not have good multi-process support.

[jacobdufault]

One possible mitigation is to partially serialize indexer tasks, guaranteeing that the time different threads calling clang_parseTranslationUnit2FullArgv differs by at least, say 100ms.

sg, though I think having a dedicated job queue for doing this would work faster (no need for 100ms delays). I need to re-investigate implementing a proper job system.

If on-disk storage will ever be added to cquery, multi-process poses more problems because IPC is difficult and many embedded database does not have good multi-process support.

I'd prefer to avoid on-disk storage unless it is relatively transparent to the rest of cquery. In that case the IPC setup should not care about the actual db storage. (FWIW, there is a cache, but that is only used for startup to restore the previous state).

[jacobdufault]

Turns out that having a dedicated job/serializing these requests will really hurt index performance, as that is where most of the indexing work happens.

Ideally we can fix libclang here. The advantage of using bundled clang is we can have a custom build if needed, or a non-release/stable build.

One alternative instead of a true multi-process model is to run clang_parseTranslationUnit and then call clang_saveTranslationUnit in a separate binary. The main cquery process then loads it via clang_createTranslationUnit. This will almost certainly hurt indexing performance but it may be significantly simpler than trying a full multi-process model.