[PATCH] D70600: [Error] Add stack traces for llvm::Error invariant violations.

Thu Jan 2 10:08:18 PST 2020

lhames marked 2 inline comments as done.
lhames added inline comments.

================
Comment at: llvm/lib/Support/Error.cpp:86-105
+void fatalCantFailUnhandledError(Error Err, const char *Msg) {
+  if (!Msg)
+    Msg = "Failure value returned from cantFail wrapped call";
+  std::string Str;
+  {
+    raw_string_ostream OS(Str);
+    OS << Msg << "\n" << Err << "\n";
----------------
dblaikie wrote:
> lhames wrote:
> > dblaikie wrote:
> > > I was going to ask - why all this rather than just asserting and letting the existing crash reporting stuff work. But I guess that crash reporting stuff only works for clang but not other LLVM tools? Perhaps it could be made to work? (though perhaps that's too much work - guess it involves reserving memory for use safely during crashes, etc))
> > > 
> > > Hmm, I guess it's not entirely about the clang crash reporter - a simple assert failure in llvm-dwarfdump does at least print the stack trace:
> > > 
> > >   llvm-dwarfdump-tot: /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:632: int main(int, char **): Assertion `false' failed.
> > >   Stack dump:
> > >   0.      Program arguments: llvm-dwarfdump-tot -debug-info -v loc.o 
> > >    #0 0x000000000145b977 llvm::sys::PrintStackTrace(llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/Support/Unix/Signals.inc:548:11
> > >    #1 0x000000000145bb19 PrintStackTraceSignalHandler(void*) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/Support/Unix/Signals.inc:609: 1
> > > 
> > > So, yeah - why not just an assert? (or wasn't that what the failure mode was before this change)
> > > 
> > > Oh, I see it was unreachable and still has an unreachable - that might make this error message a bit redundant - printing the stack trace & then unreachable, which will print the stack trace again?
> > > 
> > > (the ErrorTraces part is value-add/new functionality here, for sure & assert/unreachable wouldn't ever provide that functionality of course)
> > > I was going to ask - why all this rather than just asserting and letting the existing crash reporting stuff work.
> > 
> > The benefit to printing ourselves is that we can disambiguate the stack traces ("this is for the error, this is for where you dropped it") and ensure (by calling PrintStackTrace manually) that these two things are rendered side-by-side. I have not satisfied myself that assertions will always generate a similar trace (and not be intercepted by some crash logging tool) yet, but if that's the case then we can just do that.
> Yeah, the current error message behavior I'm getting is a bit more than desirable, I imagine (the "discarded from" and "?
> 
> Program aborted due to an unhandled Error. Error message:
> "version 6 of .debug_addr section at offset 0x0 is not supported"
> Error thrown from:
>  #0 0x00000000014751a7 llvm::sys::PrintStackTrace(llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/Support/Unix/Sign
> als.inc:548:11
>  #1 0x00000000013dd931 llvm::detail::annotateErrorWithTrace(llvm::ErrorInfoBase&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/Suppo
> rt/Error.cpp:64:3
>  #2 0x0000000000d098d5 llvm::Error llvm::make_error<llvm::StringError, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocat
> or<char> >&, std::error_code&>(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&, std::error_code&) /usr/loca
> l/google/home/blaikie/dev/llvm/src/llvm/include/llvm/Support/Error.h:356:16
>  #3 0x0000000000d2de7b llvm::Error llvm::createStringError<unsigned short, unsigned long>(std::error_code, char const*, unsigned short const
> &, unsigned long const&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/include/llvm/Support/Error.h:1211:1
>  #4 0x0000000000d2d231 llvm::DWARFDebugAddrTable::extract(llvm::DWARFDataExtractor, unsigned long*, unsigned short, unsigned char, std::func
> tion<void (llvm::Error)>) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/DebugInfo/DWARF/DWARFDebugAddr.cpp:90:5
>  #5 0x0000000000cf470e dumpAddrSection(llvm::raw_ostream&, llvm::DWARFDataExtractor&, llvm::DIDumpOptions, unsigned short, unsigned char) /u
> sr/local/google/home/blaikie/dev/llvm/src/llvm/lib/DebugInfo/DWARF/DWARFContext.cpp:250:21
>  #6 0x0000000000cf1a9c llvm::DWARFContext::dump(llvm::raw_ostream&, llvm::DIDumpOptions, std::array<llvm::Optional<unsigned long>, 28ul>) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/DebugInfo/DWARF/DWARFContext.cpp:537:18
>  #7 0x0000000000cbe626 dumpObjectFile(llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:447:3
>  #8 0x0000000000cd83ed std::_Function_handler<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&), bool (*)(llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>::_M_invoke(std::_Any_data const&, llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine&&, llvm::raw_ostream&) /usr/local/google/home/blaikie/install/bin/../lib/gcc/x86_64-pc-linux-gnu/8.1.0/../../../../include/c++/8.1.0/bits/std_function.h:282:2
>  #9 0x0000000000cc9ade std::function<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>::operator()(llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&) const /usr/local/google/home/blaikie/install/bin/../lib/gcc/x86_64-pc-linux-gnu/8.1.0/../../../../include/c++/8.1.0/bits/std_function.h:687:7
> #10 0x0000000000cbe90d handleBuffer(llvm::StringRef, llvm::MemoryBufferRef, std::function<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>, llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:494:14
> #11 0x0000000000cbe131 handleFile(llvm::StringRef, std::function<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>, llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:528:3
> #12 0x0000000000cbda32 main /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:643:7
> #13 0x00007f187e56552b __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x2352b)
> #14 0x0000000000caf02a _start (/usr/local/google/home/blaikie/dev/llvm/build/default/bin/llvm-dwarfdump+0xcaf02a)
> Error discarded from:
>  #0 0x00000000014751a7 llvm::sys::PrintStackTrace(llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/Support/Unix/Signals.inc:548:11
>  #1 0x00000000013de260 llvm::Error::fatalUncheckedError() const /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/Support/Error.cpp:172:3
>  #2 0x0000000000cb517a llvm::Error::assertIsChecked() /usr/local/google/home/blaikie/dev/llvm/src/llvm/include/llvm/Support/Error.h:286:3
>  #3 0x0000000000cb3f3c llvm::Error::~Error() /usr/local/google/home/blaikie/dev/llvm/src/llvm/include/llvm/Support/Error.h:245:5
>  #4 0x0000000000cf47e2 dumpAddrSection(llvm::raw_ostream&, llvm::DWARFDataExtractor&, llvm::DIDumpOptions, unsigned short, unsigned char) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/DebugInfo/DWARF/DWARFContext.cpp:250:15
>  #5 0x0000000000cf1a9c llvm::DWARFContext::dump(llvm::raw_ostream&, llvm::DIDumpOptions, std::array<llvm::Optional<unsigned long>, 28ul>) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/DebugInfo/DWARF/DWARFContext.cpp:537:18
>  #6 0x0000000000cbe626 dumpObjectFile(llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:447:3
>  #7 0x0000000000cd83ed std::_Function_handler<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&), bool (*)(llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>::_M_invoke(std::_Any_data const&, llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine&&, llvm::raw_ostream&) /usr/local/google/home/blaikie/install/bin/../lib/gcc/x86_64-pc-linux-gnu/8.1.0/../../../../include/c++/8.1.0/bits/std_function.h:282:2
>  #8 0x0000000000cc9ade std::function<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>::operator()(llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&) const /usr/local/google/home/blaikie/install/bin/../lib/gcc/x86_64-pc-linux-gnu/8.1.0/../../../../include/c++/8.1.0/bits/std_function.h:687:7
>  #9 0x0000000000cbe90d handleBuffer(llvm::StringRef, llvm::MemoryBufferRef, std::function<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>, llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:494:14
> #10 0x0000000000cbe131 handleFile(llvm::StringRef, std::function<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>, llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:528:3
> #11 0x0000000000cbda32 main /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:643:7
> #12 0x00007f187e56552b __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x2352b)
> #13 0x0000000000caf02a _start (/usr/local/google/home/blaikie/dev/llvm/build/default/bin/llvm-dwarfdump+0xcaf02a)
> Stack dump:
> 0.      Program arguments: /usr/local/google/home/blaikie/dev/llvm/build/default/bin/llvm-dwarfdump -debug-addr x.o 
>  #0 0x00000000014751a7 llvm::sys::PrintStackTrace(llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/Support/Unix/Signals.inc:548:11
>  #1 0x0000000001475349 PrintStackTraceSignalHandler(void*) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/Support/Unix/Signals.inc:609:1
>  #2 0x0000000001473c2b llvm::sys::RunSignalHandlers() /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/Support/Signals.cpp:67:5
>  #3 0x0000000001475ac5 SignalHandler(int) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/Support/Unix/Signals.inc:390:1
>  #4 0x00007f187f8553a0 __restore_rt (/lib/x86_64-linux-gnu/libpthread.so.0+0x123a0)
>  #5 0x00007f187e578cfb raise (/lib/x86_64-linux-gnu/libc.so.6+0x36cfb)
>  #6 0x00007f187e5638ad abort (/lib/x86_64-linux-gnu/libc.so.6+0x218ad)
>  #7 0x00000000013de27e (/usr/local/google/home/blaikie/dev/llvm/build/default/bin/llvm-dwarfdump+0x13de27e)
>  #8 0x0000000000cb517a llvm::Error::assertIsChecked() /usr/local/google/home/blaikie/dev/llvm/src/llvm/include/llvm/Support/Error.h:286:3
>  #9 0x0000000000cb3f3c llvm::Error::~Error() /usr/local/google/home/blaikie/dev/llvm/src/llvm/include/llvm/Support/Error.h:245:5
> #10 0x0000000000cf47e2 dumpAddrSection(llvm::raw_ostream&, llvm::DWARFDataExtractor&, llvm::DIDumpOptions, unsigned short, unsigned char) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/DebugInfo/DWARF/DWARFContext.cpp:250:15
> #11 0x0000000000cf1a9c llvm::DWARFContext::dump(llvm::raw_ostream&, llvm::DIDumpOptions, std::array<llvm::Optional<unsigned long>, 28ul>) /usr/local/google/home/blaikie/dev/llvm/src/llvm/lib/DebugInfo/DWARF/DWARFContext.cpp:537:18
> #12 0x0000000000cbe626 dumpObjectFile(llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:447:3
> #13 0x0000000000cd83ed std::_Function_handler<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&), bool (*)(llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>::_M_invoke(std::_Any_data const&, llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine&&, llvm::raw_ostream&) /usr/local/google/home/blaikie/install/bin/../lib/gcc/x86_64-pc-linux-gnu/8.1.0/../../../../include/c++/8.1.0/bits/std_function.h:282:2
> #14 0x0000000000cc9ade std::function<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>::operator()(llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&) const /usr/local/google/home/blaikie/install/bin/../lib/gcc/x86_64-pc-linux-gnu/8.1.0/../../../../include/c++/8.1.0/bits/std_function.h:687:7
> #15 0x0000000000cbe90d handleBuffer(llvm::StringRef, llvm::MemoryBufferRef, std::function<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>, llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:494:14
> #16 0x0000000000cbe131 handleFile(llvm::StringRef, std::function<bool (llvm::object::ObjectFile&, llvm::DWARFContext&, llvm::Twine, llvm::raw_ostream&)>, llvm::raw_ostream&) /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:528:3
> #17 0x0000000000cbda32 main /usr/local/google/home/blaikie/dev/llvm/src/llvm/tools/llvm-dwarfdump/llvm-dwarfdump.cpp:643:7
> #18 0x00007f187e56552b __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x2352b)
> #19 0x0000000000caf02a _start (/usr/local/google/home/blaikie/dev/llvm/build/default/bin/llvm-dwarfdump+0xcaf02a)
> Aborted
> 
> 
> (wonder if there's anything we can do about making these things more readable in general - line wrapping, colours, etc? even just some blank lines/bigger/bolder headers at the start of each stack trace might be helpful - but that sort of thing probably wouldn't be in this patch, of course)
> 
> If you're set on not producing a separate/duplicate stack trace from the one general stack dump one, fair enough/guess I can't talk you out of it & follow up patches could help make it more legible, for sure. (trimming the top few stack frames to get back up into user code/through the llvm::Error implementation details (something the generic code can't reasonably do), maybe pruning the common stack frames between the thrown/dropped stack? etc)
> Yeah, the current error message behavior I'm getting is a bit more than desirable...

I think stack traces are often long, and since this involves two it's going to be twice as long. I wonder if adding more verbiage at the top might actually help in this case, especially for people who will encounter this infrequently:

"Program crashed due to an unhandled error. The following two stack traces describe where the unhandled error was generated, and where it was discarded while in the unchecked state:"

I love the idea of adding line wrapping/colors to make this more readable, but I think that should just be applied to stack traces in general. I don't think it's specific to this patch.

Trimming the top few frames sounds *excellent*. I was thinking of proposing that myself. What about a "DropNFrames[=0]" argument to sys::PrintStackTrace for people who know their call to PrintStackTrace will sit some number of frames inside some uninteresting error handling machinery?

I love the idea of pruning common frames, but I can't figure out how to render it in a way that won't end up taking more cognitive effort to parse than just presenting two traces. Very happy to take suggestions on it, but I think it's something we could address in a follow-up.

================
Comment at: llvm/lib/Support/InitLLVM.cpp:32-34
+  if (getenv("LLVM_ENABLE_ERROR_TRACING"))
+    enableErrorTracing();
+
----------------
dblaikie wrote:
> lhames wrote:
> > dblaikie wrote:
> > > If the code for this is always going to be present - what's the benefit from using a side table rather than making Error itself a little bigger (a pointer) & skip the side table/global state/global ctors/dtors? It's not like storing lots of Errors is a supported scenario, so I doubt an extra pointer in an Error would significantly increase memory usage at any point?
> > It's sort of much-of-a-muchness. We do support multiple in-flight errors, so I like the idea of not increasing the size of ErrorInfo for something that won't be used 99.9% of the time.
> I'd probably lean towards adding the extra pointer until there's a real use case for Error that has scaling problems because of the size rather than adding the side table now. Global variables/global ctors/dtors are something I think we're generally trying to avoid in LLVM (so users of LLVM don't have to pay for things they don't need - in the form of global ctors that hurt those users startup time) (though the cl::opt is the biggest perpetrator & hasn't been addressed yet).
> 
> Not super relevant, but FWIW, assigning to and reading from a unique_ptr isn't multithread safe - so you will have to make sure you call enableErrorTracing before any threads start that might create errors.
I'd be happy to switch it to a ManagedStatic (which I believe doesn't have static ctors/dtors) or a custom global with manual management and a zero-init, but I do want to keep it as a side-table.

Thanks for pointing out the unique_ptr thread safety issue. That's another reason to move away from unique_ptr here.

Repository:
  rG LLVM Github Monorepo

CHANGES SINCE LAST ACTION
  https://reviews.llvm.org/D70600/new/

https://reviews.llvm.org/D70600