New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
htfy96 opened this Issue Nov 19, 2017 · 8 comments

Comments

Projects
None yet
3 participants
@htfy96

htfy96 commented Nov 19, 2017

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 comment has been minimized.

Show comment
Hide comment
@jacobdufault

jacobdufault Nov 19, 2017

Member

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.

Member

jacobdufault commented Nov 19, 2017

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

This comment has been minimized.

Show comment
Hide comment
@htfy96

htfy96 Nov 19, 2017

@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

htfy96 commented Nov 19, 2017

@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

This comment has been minimized.

Show comment
Hide comment
@MaskRay

MaskRay Nov 28, 2017

Member

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);
Member

MaskRay commented Nov 28, 2017

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

This comment has been minimized.

Show comment
Hide comment
@jacobdufault

jacobdufault Nov 29, 2017

Member

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).

Member

jacobdufault commented Nov 29, 2017

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

This comment has been minimized.

Show comment
Hide comment
@MaskRay

MaskRay Nov 29, 2017

Member

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

Member

MaskRay commented Nov 29, 2017

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

This comment has been minimized.

Show comment
Hide comment
@MaskRay

MaskRay Nov 29, 2017

Member

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.

Member

MaskRay commented Nov 29, 2017

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

This comment has been minimized.

Show comment
Hide comment
@jacobdufault

jacobdufault Nov 30, 2017

Member

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).

Member

jacobdufault commented Nov 30, 2017

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

This comment has been minimized.

Show comment
Hide comment
@jacobdufault

jacobdufault Nov 30, 2017

Member

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.

Member

jacobdufault commented Nov 30, 2017

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment