Skip to content
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

[WIP] Add file:line information to backtraces #3170

Closed

Conversation

ysbaddaden
Copy link
Contributor

@ysbaddaden ysbaddaden commented Aug 17, 2016

This is an example of using addr2line/atos for exception backtraces (and caller). This is only tested on Linux (where addr2line is provided by binutils). It doesn't fail whenaddr2lineis unavailable but prints??:?`. Untested on OSX but should work too.

This requires the debug mode because debug location tables must be added to the executable. It could be nice to always add the file:line information, whatever the debug mode. This is easy to enable and doesn't increases the executable much (roughly 5%) but the compiler specs fail badly.

I added skips for whatever relates to some files (exceptions) to filter the backtrace from internal implementation details.

We should eventually have an executable parser (eg. ELF parser) capable to extract this information itself. But this is HARD work and will have to be duplicated for each platform (edit: actually it's not hard).

0x000000000045d9ba: Kls#callee1 at /home/github/crystal/test_addr2line.cr:3
0x0000000000428d6e: callee3 at /home/github/crystal/test_addr2line.cr:13
0x000000000042501a: ??? at /home/github/crystal/test_addr2line.cr:15
0x0000000000428c49: main at /home/julien/.cache/crystal/macro62426064.cr:12
0x00007fccf1903f45: __libc_start_main at ??:0
0x0000000000424959: ??? at ??:?
0x0000000000000000: ??? at ??:0

@ysbaddaden ysbaddaden force-pushed the core-callstack-refactor branch 3 times, most recently from 8254de3 to 3742178 Compare August 17, 2016 21:29
@ysbaddaden
Copy link
Contributor Author

Now with better commits that should be easier to read :)

This requires the executable to be built with `--debug` to include
the necessary information. Also requires the `addr2line` executable
to be installed on the machine running the binary, otherwise the
unhelpful `?:?` will be printed instead.

Somewhat demangles symbols to remove the pointers (`*` and `~`) as
well as the return type so it's easier to read.

Doesn't touch the `print_backtrace` methods that will continue to
report the raw backtrace.

closes crystal-lang#1270
Skips any call in the callstack originating from the src/exception.cr
and src/callstack.cr files that are implementation details.

closes crystal-lang#3161
@ysbaddaden ysbaddaden force-pushed the core-callstack-refactor branch from 3742178 to 0325453 Compare August 17, 2016 22:29
@ysbaddaden
Copy link
Contributor Author

And now with support for atos on OSX. All targets should now be supported.

I can't figure why CI fails so badly. I can't reproduce any of the errors 😢

@david50407
Copy link
Contributor

It seems a bug in libevent (searched from Google)

@mverzilli
Copy link

@ysbaddaden this is great! Is there any use case for keeping the hexadecimal (address?) at the beginning of the line?

@asterite
Copy link
Member

I don't know why it fails, but if I run this snippet of code:

# foo.cr
raise "OH NO!"
$ bin/crystal foo.cr
OH NO! (Exception)
Unhandled exception in spawn:
end of file reached (IO::EOFError)
# hangs there...

So that probably means there's something missing in the implementation.,,

@ysbaddaden
Copy link
Contributor Author

ysbaddaden commented Aug 19, 2016

I guess the "open the file then pass addresses as stdin" is quirky, or it should catch some errno. I'll revert to a basic "pass addresses as CLI args".

@mverzilli thats the raw symbols address. It's nit useful to most people, but maybe some would like it, so they hexdump the binary and follow what ASM is doing? I'm not sure.

@ysbaddaden
Copy link
Contributor Author

The problem is actually within Process.run which raises an IO::EOFError whenever I run the addr2line -e PROGRAM_NAME command 😢

@ysbaddaden
Copy link
Contributor Author

ysbaddaden commented Aug 19, 2016

@asterite it doesn't hang on Linux, but crashes in SignalHandler while receiving the SIGCHLD signal, because @write_pipe is closed (I was capable to find this thanks to addr2line). If I comment the line 67 then it hangs after the IO::EOFError with no backtrace.

@ysbaddaden
Copy link
Contributor Author

I found the issue and it lies in Event::SignalHandler. The pipes are closed before receiving the SIGCHLD signal (which raises the IO::EOFError and sometimes IO::Error exceptions in fibers, hence the Unhandled exceptions message). The signal is never reported back to Process so Process#wait hangs forever...

Dropping the at_exit { Event::SignalHandler.close } in src/kernel.cr fixes the issue, but I have no idea why the code was here I the first place since the pipe would be closed anyway when the process actually exits.

I wonder, thought, why the at_exit handlers are run before the exception is printed?

@ysbaddaden
Copy link
Contributor Author

Closed in favor of #3303.

@ysbaddaden ysbaddaden closed this Nov 7, 2016
@ysbaddaden ysbaddaden deleted the core-callstack-refactor branch November 7, 2016 13:39
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants