Crystal: Show shared library paths for symbols without debug info

[rdp]

We'll first make it output some "3rd party library" portions of the stacktrace:

diff --git a/src/openssl/bio.cr b/src/openssl/bio.cr
index 1c6007f..b152b18 100644
--- a/src/openssl/bio.cr
+++ b/src/openssl/bio.cr
@@ -34,6 +34,7 @@ struct OpenSSL::BIO
     end

     bread = LibCrypto::BioMethodReadOld.new do |bio, buffer, len|
+      raise "hello"
       io = Box(IO).unbox(BIO.get_data(bio))
       io.flush
       io.read(Slice.new(buffer, len)).to_i

Test program:

$ cat ssl.cr
require "http/client"
HTTP::Client.get("https://google.com")

Linux 0.31.1:

$ crystal ssl.cr
Unhandled exception: hello (Exception)
  from /usr/share/crystal/src/openssl/bio.cr:38:7 in '->'
  from BIO_read
  from ???
  from ???
  from SSL_connect
  from /usr/share/crystal/src/openssl/ssl/socket.cr:32:15 in 'initialize'
  from /usr/share/crystal/src/openssl/ssl/socket.cr:3:5 in 'new:context:sync_close:hostname'
  from /usr/share/crystal/src/http/client.cr:759:5 in 'socket'
  from /usr/share/crystal/src/http/client.cr:643:19 in 'send_request'
  from /usr/share/crystal/src/http/client.cr:580:5 in 'exec_internal_single'
  from /usr/share/crystal/src/http/client.cr:567:5 in 'exec_internal'
  from /usr/share/crystal/src/http/client.cr:563:5 in 'exec'
  from /usr/share/crystal/src/http/client.cr:685:5 in 'exec'
  from /usr/share/crystal/src/http/client.cr:717:7 in 'exec'
  from /usr/share/crystal/src/http/client.cr:389:3 in 'get'
  from ssl.cr:2:1 in '__crystal_main'
  from /usr/share/crystal/src/crystal/main.cr:97:5 in 'main_user_code'
  from /usr/share/crystal/src/crystal/main.cr:86:7 in 'main'
  from /usr/share/crystal/src/crystal/main.cr:106:3 in 'main'
  from __libc_start_main
  from ???

Same thing in gdb:

Breakpoint 1, -> () at /usr/share/crystal/src/openssl/bio.cr:38
(gdb) bt
#0  -> () at /usr/share/crystal/src/openssl/bio.cr:38
#1  0xb7e1c40b in BIO_read () from /lib/i386-linux-gnu/libcrypto.so.1.0.0
#2  0xb7f6d5fd in ?? () from /lib/i386-linux-gnu/libssl.so.1.0.0
#3  0xb7f6c6e0 in ?? () from /lib/i386-linux-gnu/libssl.so.1.0.0
#4  0xb7f81e06 in SSL_connect () from /lib/i386-linux-gnu/libssl.so.1.0.0
#5  0x081da501 in initialize () at /usr/share/crystal/src/openssl/ssl/socket.cr:32
#6  0x081da3b3 in new:context:sync_close:hostname () at /usr/share/crystal/src/openssl/ssl/socket.cr:3
#7  0x081c6718 in socket () at /usr/share/crystal/src/http/client.cr:759
#8  0x081c5d2a in send_request () at /usr/share/crystal/src/http/client.cr:643
#9  0x081c5c6c in exec_internal_single () at /usr/share/crystal/src/http/client.cr:580
#10 0x081c599d in exec_internal () at /usr/share/crystal/src/http/client.cr:567
#11 0x081c5956 in exec () at /usr/share/crystal/src/http/client.cr:563
#12 0x081c58c8 in exec () at /usr/share/crystal/src/http/client.cr:685
#13 0x081c4b34 in exec () at /usr/share/crystal/src/http/client.cr:717
#14 0x081c47e8 in get () at /usr/share/crystal/src/http/client.cr:389
#15 0x080a2528 in __crystal_main () at /home/rdp/dev/crystal/ssl.cr:2
#16 0x081e9126 in main_user_code () at /usr/share/crystal/src/crystal/main.cr:97
#17 0x081e903d in main () at /usr/share/crystal/src/crystal/main.cr:86
#18 0x080ae956 in main () at /usr/share/crystal/src/crystal/main.cr:106

It's able to detect which file it came from for those question mark lines.

OS X 0.31.1:

Unhandled exception: hello (Exception)
  from src/openssl/bio.cr:37:7 in '->'
  from BIO_read
  from ssl23_read_bytes
  from ssl23_get_server_hello
  from ssl23_connect
  from SSL_connect
  from src/openssl/ssl/socket.cr:32:15 in 'initialize'
  from src/openssl/ssl/socket.cr:3:5 in 'new:context:sync_close:hostname'
  from src/http/client.cr:759:5 in 'socket'
  from src/http/client.cr:643:19 in 'send_request'
  from src/http/client.cr:580:5 in 'exec_internal_single'
  from src/http/client.cr:567:5 in 'exec_internal'
  from src/http/client.cr:563:5 in 'exec'
  from src/http/client.cr:685:5 in 'exec'
  from src/http/client.cr:717:7 in 'exec'
  from src/http/client.cr:389:3 in 'get'
  from ssl.cr:2:1 in '__crystal_main'
  from src/crystal/main.cr:97:5 in 'main_user_code'
  from src/crystal/main.cr:86:7 in 'main'
  from src/crystal/main.cr:106:3 in 'main'

and gdb OS X:

Thread 3 hit Breakpoint 1, -> () at /Users/rdp/dev/crystal/src/openssl/bio.cr:37
37        raise "hello"
(gdb) bt
#0  -> () at /Users/rdp/dev/crystal/src/openssl/bio.cr:37
#1  0x00007fff7722f59c in BIO_read () from /usr/lib/libcrypto.35.dylib
#2  0x00007fff7889b810 in ssl23_read_bytes () from /usr/lib/libssl.35.dylib
#3  0x00007fff7889ade8 in ssl23_get_server_hello () from /usr/lib/libssl.35.dylib
#4  0x00007fff7889a536 in ssl23_connect () from /usr/lib/libssl.35.dylib
#5  0x00007fff788be816 in SSL_connect () from /usr/lib/libssl.35.dylib
#6  0x00000001001014dd in initialize () at /Users/rdp/dev/crystal/src/openssl/ssl/socket.cr:32
#7  0x0000000100101404 in new:context:sync_close:hostname () at /Users/rdp/dev/crystal/src/openssl/ssl/socket.cr:3
#8  0x00000001000f243b in socket () at /Users/rdp/dev/crystal/src/http/client.cr:759
#9  0x00000001000f1c8b in send_request () at /Users/rdp/dev/crystal/src/http/client.cr:643
#10 0x00000001000f1c1d in exec_internal_single () at /Users/rdp/dev/crystal/src/http/client.cr:580
#11 0x00000001000f19f0 in exec_internal () at /Users/rdp/dev/crystal/src/http/client.cr:567
#12 0x00000001000f19c9 in exec () at /Users/rdp/dev/crystal/src/http/client.cr:563
#13 0x00000001000f1971 in exec () at /Users/rdp/dev/crystal/src/http/client.cr:685
#14 0x00000001000f0fe4 in exec () at /Users/rdp/dev/crystal/src/http/client.cr:717
#15 0x00000001000f0d3f in get () at /Users/rdp/dev/crystal/src/http/client.cr:389
#16 0x0000000100001908 in __crystal_main () at /Users/rdp/dev/crystal/ssl.cr:2
#17 0x000000010010d56d in main_user_code () at /Users/rdp/dev/crystal/src/crystal/main.cr:97
#18 0x000000010010d4d8 in main () at /Users/rdp/dev/crystal/src/crystal/main.cr:86
#19 0x000000010000cef9 in main () at /Users/rdp/dev/crystal/src/crystal/main.cr:106

Similarly missing filenames, though it has method names correctly in OS X.

[ysbaddaden]

We can. We must detect that the address is from a dynamic library, locate it, parse it (ELF, Mach-O, ...), extract and parse the DWARF information, then keep it loaded in memory. All that for source code that isn't on the computer and we don't have any control over.

Unwinding and decoding the backtrace is already quite expensive. That's adding even more.

Is it really worth it?

[asterite]

Not worth it. You can use gdb if you really want to know that.

[rdp]

Looking at the backtrace in gdb, it doesn't mention line numbers so it's possible it doesn't have DWARF sections to parse, so loading it might not use much RAM...It may be worth it "some day" just for accuracy sake, it might not slow down backtrace generation significantly and could add more information to some backtraces in certain instances...

[ysbaddaden]

Oh, it merely identifies the loaded library file when the DWARF information isn't present. I guess it's possible.

[asterite]

I think doing this might actually be confusing to a user. Users program in Crystal, they don't need to see the backtrack going to C functions. You don't see such thing in Ruby.

So if we want to do something here we should probably hide the stack entries that point to C libraries.

[rdp]

The current question marks are a little confusing too, and it's still useful to know it went (and returned from) a 3rd party lib.  Maybe replace the from ??? with from ??? <third party?> or similar? If we include the filename I don't think it'll be confusing (currently in OS X it shows just the method name and not the filename, which is, yeah, confusing as mentioned...?

[ysbaddaden]

I think its useful to know that the exception was raised inside a C function callback (doesn't happen often). Hiding such lines would hide it and possibly cause some headhache, until you try in GDB.

[rdp]

moved to #7471 as somewhat requested

[RX14]

This is a feature request for backtrace, not emitting debug info.