Debug Info Slowing Things Down?!

I think that debug info is slowing a self-hosting build down. This build has been going for ages now and shows no sign of quitting. To reproduce, build a Release+Asserts build of clang. Then use that to build a Debug+Asserts version. Include all of the bells and whistles, like the clang-extras and compiler-rt libraries.

The reason I suspect debug info is because of this stack trace:

[morbo:llvm] lldb -p 92084
Attaching to process with:
    process attach -p 92084
Process 92084 stopped
Executable module set to "/Users/morbo/llvm/llvm-clean.obj/Release+Asserts/bin/clang".
Architecture set to: x86_64-apple-macosx.
(lldb) bt
* thread #1: tid = 0xbebaf, 0x000000010c5f6dc1 clang`llvm::SmallPtrSetImpl::insert_imp(void const*) + 161, queue = 'com.apple.main-thread, stop reason = signal SIGSTOP
    frame #0: 0x000000010c5f6dc1 clang`llvm::SmallPtrSetImpl::insert_imp(void const*) + 161
    frame #1: 0x000000010c5147df clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 47
    frame #2: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
    frame #3: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #4: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #5: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
    frame #6: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
    frame #7: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #8: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
    frame #9: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
    frame #10: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #11: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #12: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #13: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #14: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #15: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #16: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #17: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #18: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #19: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
    frame #20: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
    frame #21: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #22: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #23: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #24: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #25: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #26: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
    frame #27: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
    frame #28: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #29: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
    frame #30: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
    frame #31: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #32: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #33: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #34: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #35: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #36: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #37: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #38: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #39: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #40: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
    frame #41: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
    frame #42: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #43: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #44: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #45: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #46: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #47: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #48: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #49: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #50: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #51: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #52: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #53: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
    frame #54: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
    frame #55: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #56: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #57: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #58: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
    frame #59: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
    frame #60: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
    frame #61: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
    frame #62: 0x000000010c5140e2 clang`llvm::DebugInfoFinder::processScope(llvm::DIScope) + 50
    frame #63: 0x000000010c514895 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 229
    frame #64: 0x000000010c5141e2 clang`llvm::DebugInfoFinder::processScope(llvm::DIScope) + 306
    frame #65: 0x000000010c514cdb clang`llvm::DebugInfoFinder::processLocation(llvm::Module const&, llvm::DILocation) + 91
    frame #66: 0x000000010c5af3d6 clang`(anonymous namespace)::Verifier::visitInstruction(llvm::Instruction&) + 2278
    frame #67: 0x000000010c5b0bc1 clang`(anonymous namespace)::Verifier::VerifyCallSite(llvm::CallSite) + 1489
    frame #68: 0x000000010c5af949 clang`(anonymous namespace)::Verifier::visitCallInst(llvm::CallInst&) + 73
    frame #69: 0x000000010c5adbea clang`llvm::InstVisitor<(anonymous namespace)::Verifier, void>::visit(llvm::Instruction&) + 10058
    frame #70: 0x000000010c5aa56b clang`(anonymous namespace)::Verifier::runOnFunction(llvm::Function&) + 1611
    frame #71: 0x000000010c58963b clang`llvm::FPPassManager::runOnFunction(llvm::Function&) + 347
    frame #72: 0x000000010c588e4b clang`llvm::legacy::FunctionPassManagerImpl::run(llvm::Function&) + 235
    frame #73: 0x000000010c588d26 clang`llvm::legacy::FunctionPassManager::run(llvm::Function&) + 86
    frame #74: 0x000000010ad490f4 clang`clang::EmitBackendOutput(clang::DiagnosticsEngine&, clang::CodeGenOptions const&, clang::TargetOptions const&, clang::LangOptions const&, llvm::Module*, clang::BackendAction, llvm::raw_ostream*) + 5492
    frame #75: 0x000000010ae47b45 clang`clang::BackendConsumer::HandleTranslationUnit(clang::ASTContext&) + 453
    frame #76: 0x000000010ae99764 clang`clang::ParseAST(clang::Sema&, bool, bool) + 516
    frame #77: 0x000000010ae469da clang`clang::CodeGenAction::ExecuteAction() + 122
    frame #78: 0x000000010abf3e66 clang`clang::FrontendAction::Execute() + 134
    frame #79: 0x000000010abcf70d clang`clang::CompilerInstance::ExecuteAction(clang::FrontendAction&) + 973
    frame #80: 0x000000010ab97a44 clang`clang::ExecuteCompilerInvocation(clang::CompilerInstance*) + 4276
    frame #81: 0x000000010ab8f843 clang`cc1_main(char const**, char const**, char const*, void*) + 835
    frame #82: 0x000000010ab93d52 clang`main + 1138
    frame #83: 0x00007fff910165fd libdyld.dylib`start + 1
    frame #84: 0x00007fff910165fd libdyld.dylib`start + 1
(lldb)

This is the command:

morbo 92084 100.0 2.3 2888888 380520 s002 R+ 5:47PM 1:10.64 /Users/morbo/llvm/llvm-clean.obj/Release+Asserts/bin/clang -cc1 -triple x86_64-apple-macosx10.9.0 -emit-obj -mrelax-all -disable-free -main-file-name LLVMTidyModule.cpp -mrelocation-model pic -pic-level 2 -mdisable-fp-elim -relaxed-aliasing -masm-verbose -munwind-tables -target-cpu core2 -target-linker-version 136 -gdwarf-2 -coverage-file /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/Debug+Asserts/LLVMTidyModule.o -resource-dir /Users/morbo/llvm/llvm-clean.obj/Release+Asserts/bin/../lib/clang/3.4 -dependency-file /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/Debug+Asserts/LLVMTidyModule.d.tmp -MP -MT /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/Debug+Asserts/LLVMTidyModule.o -MT /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/Debug+Asserts/LLVMTidyModule.d -D _DEBUG -D _GNU_SOURCE -D __STDC_CONSTANT_MACROS -D __STDC_FORMAT_MACROS -D __STDC_LIMIT_MACROS -I /Users/morbo/llvm/llvm.obj/include -I /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm -I /Users/morbo/llvm/llvm.src/include -I /Users/morbo/llvm/llvm.src/tools/clang/tools/extra/clang-tidy/llvm -I /Users/morbo/llvm/llvm.src/tools/clang/tools/extra/clang-tidy/llvm/../../../../include -I /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/../../../../include -I /Users/morbo/llvm/llvm-clean.install/lib/c++/v1 -stdlib=libc++ -Woverloaded-virtual -Wcast-qual -Wno-long-long -Wall -W -Wno-unused-parameter -Wwrite-strings -Wcovered-switch-default -Wno-uninitialized -Wno-missing-field-initializers -pedantic -fdeprecated-macro -fdebug-compilation-dir /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm -ferror-limit 19 -fmessage-length 191 -fvisibility-inlines-hidden -stack-protector 1 -mstackrealign -fblocks -fno-rtti -fobjc-runtime=macosx-10.9.0 -fencode-extended-block-signature -fno-common -fdiagnostics-show-option -fcolor-diagnostics -vectorize-slp -o /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/Debug+Asserts/LLVMTidyModule.o -x c++ /Users/morbo/llvm/llvm.src/tools/clang/tools/extra/clang-tidy/llvm/LLVMTidyModule.cpp

-bw

Hi Bill

Is this a recent regression? I recently changed the debug info verifier to fix a bug.

Thanks,
Manman

I think that debug info is slowing a self-hosting build down. This build has been going for ages now and shows no sign of quitting. To reproduce, build a Release+Asserts build of clang. Then use that to build a Debug+Asserts version. Include all of the bells and whistles, like the clang-extras and compiler-rt libraries.

The reason I suspect debug info is because of this stack trace:

[morbo:llvm] lldb -p 92084
Attaching to process with:
   process attach -p 92084
Process 92084 stopped
Executable module set to "/Users/morbo/llvm/llvm-clean.obj/Release+Asserts/bin/clang".
Architecture set to: x86_64-apple-macosx.
(lldb) bt
* thread #1: tid = 0xbebaf, 0x000000010c5f6dc1 clang`llvm::SmallPtrSetImpl::insert_imp(void const*) + 161, queue = 'com.apple.main-thread, stop reason = signal SIGSTOP
   frame #0: 0x000000010c5f6dc1 clang`llvm::SmallPtrSetImpl::insert_imp(void const*) + 161
   frame #1: 0x000000010c5147df clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 47
   frame #2: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
   frame #3: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #4: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #5: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
   frame #6: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
   frame #7: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #8: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
   frame #9: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
   frame #10: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #11: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #12: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #13: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #14: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #15: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #16: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #17: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #18: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #19: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
   frame #20: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
   frame #21: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #22: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #23: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #24: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #25: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #26: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
   frame #27: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
   frame #28: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #29: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
   frame #30: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
   frame #31: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #32: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #33: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #34: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #35: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #36: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #37: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #38: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #39: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #40: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
   frame #41: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
   frame #42: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #43: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #44: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #45: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #46: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #47: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #48: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #49: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #50: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #51: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #52: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #53: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
   frame #54: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
   frame #55: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #56: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #57: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #58: 0x000000010c5145f3 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 547
   frame #59: 0x000000010c514695 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 709
   frame #60: 0x000000010c5148c4 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 276
   frame #61: 0x000000010c514701 clang`llvm::DebugInfoFinder::processType(llvm::DIType) + 817
   frame #62: 0x000000010c5140e2 clang`llvm::DebugInfoFinder::processScope(llvm::DIScope) + 50
   frame #63: 0x000000010c514895 clang`llvm::DebugInfoFinder::processSubprogram(llvm::DISubprogram) + 229
   frame #64: 0x000000010c5141e2 clang`llvm::DebugInfoFinder::processScope(llvm::DIScope) + 306
   frame #65: 0x000000010c514cdb clang`llvm::DebugInfoFinder::processLocation(llvm::Module const&, llvm::DILocation) + 91
   frame #66: 0x000000010c5af3d6 clang`(anonymous namespace)::Verifier::visitInstruction(llvm::Instruction&) + 2278
   frame #67: 0x000000010c5b0bc1 clang`(anonymous namespace)::Verifier::VerifyCallSite(llvm::CallSite) + 1489
   frame #68: 0x000000010c5af949 clang`(anonymous namespace)::Verifier::visitCallInst(llvm::CallInst&) + 73
   frame #69: 0x000000010c5adbea clang`llvm::InstVisitor<(anonymous namespace)::Verifier, void>::visit(llvm::Instruction&) + 10058
   frame #70: 0x000000010c5aa56b clang`(anonymous namespace)::Verifier::runOnFunction(llvm::Function&) + 1611
   frame #71: 0x000000010c58963b clang`llvm::FPPassManager::runOnFunction(llvm::Function&) + 347
   frame #72: 0x000000010c588e4b clang`llvm::legacy::FunctionPassManagerImpl::run(llvm::Function&) + 235
   frame #73: 0x000000010c588d26 clang`llvm::legacy::FunctionPassManager::run(llvm::Function&) + 86
   frame #74: 0x000000010ad490f4 clang`clang::EmitBackendOutput(clang::DiagnosticsEngine&, clang::CodeGenOptions const&, clang::TargetOptions const&, clang::LangOptions const&, llvm::Module*, clang::BackendAction, llvm::raw_ostream*) + 5492
   frame #75: 0x000000010ae47b45 clang`clang::BackendConsumer::HandleTranslationUnit(clang::ASTContext&) + 453
   frame #76: 0x000000010ae99764 clang`clang::ParseAST(clang::Sema&, bool, bool) + 516
   frame #77: 0x000000010ae469da clang`clang::CodeGenAction::ExecuteAction() + 122
   frame #78: 0x000000010abf3e66 clang`clang::FrontendAction::Execute() + 134
   frame #79: 0x000000010abcf70d clang`clang::CompilerInstance::ExecuteAction(clang::FrontendAction&) + 973
   frame #80: 0x000000010ab97a44 clang`clang::ExecuteCompilerInvocation(clang::CompilerInstance*) + 4276
   frame #81: 0x000000010ab8f843 clang`cc1_main(char const**, char const**, char const*, void*) + 835
   frame #82: 0x000000010ab93d52 clang`main + 1138
   frame #83: 0x00007fff910165fd libdyld.dylib`start + 1
   frame #84: 0x00007fff910165fd libdyld.dylib`start + 1
(lldb)

This is the command:

morbo 92084 100.0 2.3 2888888 380520 s002 R+ 5:47PM 1:10.64 /Users/morbo/llvm/llvm-clean.obj/Release+Asserts/bin/clang -cc1 -triple x86_64-apple-macosx10.9.0 -emit-obj -mrelax-all -disable-free -main-file-name LLVMTidyModule.cpp -mrelocation-model pic -pic-level 2 -mdisable-fp-elim -relaxed-aliasing -masm-verbose -munwind-tables -target-cpu core2 -target-linker-version 136 -gdwarf-2 -coverage-file /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/Debug+Asserts/LLVMTidyModule.o -resource-dir /Users/morbo/llvm/llvm-clean.obj/Release+Asserts/bin/../lib/clang/3.4 -dependency-file /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/Debug+Asserts/LLVMTidyModule.d.tmp -MP -MT /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/Debug+Asserts/LLVMTidyModule.o -MT /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/Debug+Asserts/LLVMTidyModule.d -D _DEBUG -D _GNU_SOURCE -D __STDC_CONSTANT_MACROS -D __STD!

C_!

FORMAT_MACROS -D __STDC_LIMIT_MACROS -I /Users/morbo/llvm/llvm.obj/include -I /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm -I /Users/morbo/llvm/llvm.src/include -I /Users/morbo/llvm/llvm.src/tools/clang/tools/extra/clang-tidy/llvm -I /Users/morbo/llvm/llvm.src/tools/clang/tools/extra/clang-tidy/llvm/../../../../include -I /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm/../../../../include -I /Users/morbo/llvm/llvm-clean.install/lib/c++/v1 -stdlib=libc++ -Woverloaded-virtual -Wcast-qual -Wno-long-long -Wall -W -Wno-unused-parameter -Wwrite-strings -Wcovered-switch-default -Wno-uninitialized -Wno-missing-field-initializers -pedantic -fdeprecated-macro -fdebug-compilation-dir /Users/morbo/llvm/llvm.obj/tools/clang/tools/extra/clang-tidy/llvm -ferror-limit 19 -fmessage-length 191 -fvisibility-inlines-hidden -stack-protector 1 -mstackrealign -fblocks -fno-rtti -fobjc-runtime=macosx-10.9.0 -fencode-extended-block-signature -fno-common -fd!

i!

I think it might be. I’m attaching a preprocessed file that can show the problem. Compile it with ToT.

$ clang++ -g -fvisibility-inlines-hidden -fno-exceptions -fno-rtti -fno-common -Woverloaded-virtual -Wcast-qual -fno-strict-aliasing -m64 -pedantic -Wno-long-long -Wall -W -Wno-unused-parameter -Wwrite-strings -Wcovered-switch-default -Wno-uninitialized -Wno-missing-field-initializers -c LLVMTidyModule.ii

-bw

LLVMTidyModule.ii (3.18 MB)

Hi Bill,

Thanks for the testing case. Most of the time is spent on debug info verifier.
I fixed a bug in r194974, now it takes too long to run debug info verification.

Debug info verifier is part of the verifier which is a Function Pass. Tot currently tries to pull all reachable debug info MDNodes in each function, which is too time-consuming. The correct fix seems to be separating debug info verification to its own module pass.

I will disable the debug info verifier until a correct fix is found.

Thanks,
Manman

Great! Thanks for looking into this. :slight_smile:

-bw

Hi Bill,

Thanks for the testing case. Most of the time is spent on debug info
verifier.
I fixed a bug in r194974, now it takes too long to run debug info
verification.

Debug info verifier is part of the verifier which is a Function Pass. Tot
currently tries to pull all reachable debug info MDNodes in each function,
which is too time-consuming. The correct fix seems to be separating debug
info verification to its own module pass.

I will disable the debug info verifier until a correct fix is found.

Most likely what's going on here is that we're verifying the same sets
of debug info multiple times. A way to quickly speed it up would be to
cache/memoize the nodes we've already visited.

-eric

> Hi Bill,
>
> Thanks for the testing case. Most of the time is spent on debug info
> verifier.
> I fixed a bug in r194974, now it takes too long to run debug info
> verification.
>
> Debug info verifier is part of the verifier which is a Function Pass. Tot
> currently tries to pull all reachable debug info MDNodes in each
function,
> which is too time-consuming. The correct fix seems to be separating debug
> info verification to its own module pass.
>
> I will disable the debug info verifier until a correct fix is found.
>

Most likely what's going on here is that we're verifying the same sets
of debug info multiple times. A way to quickly speed it up would be to
cache/memoize the nodes we've already visited.

Yes, we are verifying some debug info MDNodes multiple times. I am not sure
if caching MDNodes visited in one function makes sense.
For each function, we apply a series of passes, so there are optimizations
run between verifying one function and verifying another function.
The content of MDNodes verified in one function can potentially change when
we are trying to verify another function.

Manman

> Hi Bill,
>
> Thanks for the testing case. Most of the time is spent on debug info
> verifier.
> I fixed a bug in r194974, now it takes too long to run debug info
> verification.
>
> Debug info verifier is part of the verifier which is a Function Pass.
> Tot
> currently tries to pull all reachable debug info MDNodes in each
> function,
> which is too time-consuming. The correct fix seems to be separating
> debug
> info verification to its own module pass.
>
> I will disable the debug info verifier until a correct fix is found.
>

Most likely what's going on here is that we're verifying the same sets
of debug info multiple times. A way to quickly speed it up would be to
cache/memoize the nodes we've already visited.

Yes, we are verifying some debug info MDNodes multiple times. I am not sure
if caching MDNodes visited in one function makes sense.
For each function, we apply a series of passes, so there are optimizations
run between verifying one function and verifying another function.
The content of MDNodes verified in one function can potentially change when
we are trying to verify another function.

I figured this was happen at bitcode load time. If we're verifying
anywhere else then we should still cache per-function what we've
analyzed.

-eric

>
>
>
>>
>> > Hi Bill,
>> >
>> > Thanks for the testing case. Most of the time is spent on debug info
>> > verifier.
>> > I fixed a bug in r194974, now it takes too long to run debug info
>> > verification.
>> >
>> > Debug info verifier is part of the verifier which is a Function Pass.
>> > Tot
>> > currently tries to pull all reachable debug info MDNodes in each
>> > function,
>> > which is too time-consuming. The correct fix seems to be separating
>> > debug
>> > info verification to its own module pass.
>> >
>> > I will disable the debug info verifier until a correct fix is found.
>> >
>>
>> Most likely what's going on here is that we're verifying the same sets
>> of debug info multiple times. A way to quickly speed it up would be to
>> cache/memoize the nodes we've already visited.
>
>
> Yes, we are verifying some debug info MDNodes multiple times. I am not
sure
> if caching MDNodes visited in one function makes sense.
> For each function, we apply a series of passes, so there are
optimizations
> run between verifying one function and verifying another function.
> The content of MDNodes verified in one function can potentially change
when
> we are trying to verify another function.
>

I figured this was happen at bitcode load time. If we're verifying
anywhere else then we should still cache per-function what we've
analyzed.

Verifier can be called a few times, for LTO, it is called 3 times.
It is common that we call verifier before optimization and on completion of
optimization.

From the current source codes, verifier is grouped with a few analysis

passes, so it should be
okay to cache the results. But there is no guarantee that verifier will not
be grouped together with
optimization passes in a single FPPassManager. In that case, caching may
not make sense since
the optimization passes can modify the MDNodes.

Currently we perform module-level verification in doFinalization which is
not ideal. For example, if we have
two verifier passes, doFinalization for the two passes will be run at the
end, which is a total duplication since they
will be verifying the same module twice, at the end of optimizations.

So that is one advantage of moving debug info verifier to its own module
pass.

Manman