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

Show shared library paths for symbols without debug info #8534

Closed
rdp opened this issue Nov 29, 2019 · 10 comments · Fixed by #11408
Closed

Show shared library paths for symbols without debug info #8534

rdp opened this issue Nov 29, 2019 · 10 comments · Fixed by #11408

Comments

@rdp
Copy link
Contributor

rdp commented Nov 29, 2019

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
Copy link
Contributor

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
Copy link
Member

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

@rdp
Copy link
Contributor Author

rdp commented Nov 30, 2019

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
Copy link
Contributor

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

@asterite
Copy link
Member

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
Copy link
Contributor Author

rdp commented Nov 30, 2019

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
Copy link
Contributor

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
Copy link
Contributor Author

rdp commented Dec 8, 2019

moved to #7471 as somewhat requested

@rdp rdp closed this as completed Dec 8, 2019
@RX14 RX14 changed the title backtrace should include filenames of libraries Show shared library paths for symbols without debug info Dec 8, 2019
@RX14 RX14 reopened this Dec 8, 2019
@RX14
Copy link
Contributor

RX14 commented Dec 8, 2019

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

@rdp
Copy link
Contributor Author

rdp commented Nov 6, 2021

#9209 may have clues

rdp added a commit to rdp/crystal that referenced this issue Nov 6, 2021

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature. The key has expired.
rdp added a commit to rdp/crystal that referenced this issue Nov 7, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants