[LLVMdev] Debug Info Slowing Things Down?!

Eric Christopher echristo at gmail.com
Mon Nov 18 11:55:20 PST 2013 

On Mon, Nov 18, 2013 at 11:06 AM, Manman Ren <manman.ren at gmail.com> wrote:
>
>
>
> On Mon, Nov 18, 2013 at 10:55 AM, Eric Christopher <echristo at gmail.com>
> wrote:
>>
>> On Sun, Nov 17, 2013 at 6:35 PM, Manman Ren <manman.ren at gmail.com> wrote:
>> > 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

> Manman
>
>>
>>
>> -eric
>>
>> > Thanks,
>> > Manman
>> >
>> >
>> >
>> > On Sun, Nov 17, 2013 at 6:04 PM, Bill Wendling <isanbard at gmail.com>
>> > wrote:
>> >>
>> >> 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
>> >>
>> >>
>> >>
>> >>
>> >> On Nov 17, 2013, at 6:01 PM, Manman Ren <mren at apple.com> wrote:
>> >>
>> >> > Hi Bill
>> >> >
>> >> > Is this a recent regression? I recently changed the debug info
>> >> > verifier
>> >> > to fix a bug.
>> >> >
>> >> > Thanks,
>> >> > Manman
>> >> >
>> >> >> On Nov 17, 2013, at 5:52 PM, Bill Wendling <isanbard at gmail.com>
>> >> >> wrote:
>> >> >>
>> >> >> 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
>> >> >> -fdi!
>> >> >> agnostics-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
>> >> >>
>> >> >>
>> >> >> _______________________________________________
>> >> >> LLVM Developers mailing list
>> >> >> LLVMdev at cs.uiuc.edu         http://llvm.cs.uiuc.edu
>> >> >> http://lists.cs.uiuc.edu/mailman/listinfo/llvmdev
>> >>
>> >>
>> >
>
>

More information about the llvm-dev mailing list