Resolve C function names when sampling#282
Conversation
|
@acj Thanks for trying to solve this problem 👍 It still prints long sleep, I use ruby $ ruby -v
ruby 2.7.2p137 (2020-10-01 revision 5445e04352) [x86_64-linux]
$ ruby -rrbconfig -e 'puts RbConfig::CONFIG["CFLAGS"]'
-O3 -ggdb3 -Wall -Wextra -Wdeprecated-declarations -Wduplicated-cond -Wimplicit-function-declaration -Wimplicit-int -Wmisleading-indentation -Wpointer-arith -Wwrite-strings -Wimplicit-fallthrough=0 -Wmissing-noreturn -Wno-cast-function-type -Wno-constant-logical-operand -Wno-long-long -Wno-missing-field-initializers -Wno-overlength-strings -Wno-packed-bitfield-compat -Wno-parentheses-equality -Wno-self-assign -Wno-tautological-compare -Wno-unused-parameter -Wno-unused-value -Wsuggest-attribute=format -Wsuggest-attribute=noreturn -Wunused-variable -fPIC
How to find a cause of the problem? |
|
@ilyazub Thanks for trying it out. I can repro the behavior you're seeing with rbenv (ruby 2.7.2, rbenv with default flags, Linux 5.4.0 x64_64). The ruby binary needs to have debug symbols for this to work, and the rbenv build doesn't seem to include them by default. I'm able to resolve C symbols on Linux when I compile ruby from source with But it doesn't work with rbenv even if I pass the same full set of flags using It would be neat if we could find a heuristic to locate the global symbols address like rbspy does for If you still have trouble after compiling with debug symbols (if you can), please try running rbspy with |
|
@acj This is amazing! I've been wanting to do this for years and never had any idea how to start, it's so exciting to see that this is possible!! I spent a bunch of time this morning trying to understand how this works and had a blast. I'm not sure that the I'm confused about why |
|
Oops, ignore everything I said in that last comment -- the binary I thought was stripped wasn't, and I didn't remember that |
|
Is this |
@jvns I'm glad to hear that! This has been fun to work on. Lots of little puzzles to sort out.
Ahhhh, okay. I see the same thing in my rbenv setup on Linux, and on macOS I see the In that case, I'm not sure why we can't find the global symbols in rbenv builds. Maybe the libruby part of the lookup is failing? I'll poke at this a bit more.
I think that's the gist of it, yeah. Its type is |
|
Okay, I think I found the problem. My implementation of @ilyazub, could you please try again? |
|
I tested it on Linux and it works for me now! 🎉 |
|
@acj It works! Thank you! 🤝 $ cargo run -- record -- ruby ./ci/ruby-programs/infinite.rb
Time since start: 9s. Press Ctrl+C to stop.
Summary of profiling data so far:
% self % total name
98.97 98.97 <c function> - sleep
1.03 1.03 <c function> - require
0.00 98.97 ccc - ./ci/ruby-programs/infinite.rb
0.00 98.97 block in <main> - ./ci/ruby-programs/infinite.rb
0.00 98.97 bbb - ./ci/ruby-programs/infinite.rb
0.00 98.97 aaa - ./ci/ruby-programs/infinite.rb
0.00 98.97 <main> - ./ci/ruby-programs/infinite.rb
0.00 98.97 <c function> - loop
0.00 1.03 <top (required)> - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb
0.00 1.03 <top (required)> - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/2.7.0/rubygems.rb
0.00 1.03 <top (required)> - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/2.7.0/monitor.rb
0.00 1.03 <c function> - unknown$ cargo run -- record -- ruby ../work/tmp/slow_search_parse.rb ../work/tmp/big_shopping.html
Time since start: 3s. Press Ctrl+C to stop.
Summary of profiling data so far:
% self % total name
63.16 63.16 <c function> - evaluate
15.79 15.79 <c function> - file?
10.53 10.53 <c function> - require
5.26 5.26 <c function> - readline
5.26 5.26 <c function> - read_memory
0.00 100.00 <main> - ../work/tmp/slow_search_parse.rb
0.00 63.16 xpath_internal - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/nokogiri-1.11.1-x86_64-linux/lib/nokogiri/xml/searchable.rb
0.00 63.16 xpath_impl - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/nokogiri-1.11.1-x86_64-linux/lib/nokogiri/xml/searchable.rb
0.00 63.16 css_internal - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/nokogiri-1.11.1-x86_64-linux/lib/nokogiri/xml/searchable.rb
0.00 63.16 css - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/nokogiri-1.11.1-x86_64-linux/lib/nokogiri/xml/searchable.rb
0.00 63.16 block in <main> - ../work/tmp/slow_search_parse.rb
0.00 63.16 <c function> - times
0.00 52.63 each - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/nokogiri-1.11.1-x86_64-linux/lib/nokogiri/xml/node_set.rb
0.00 52.63 block in each - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/nokogiri-1.11.1-x86_64-linux/lib/nokogiri/xml/node_set.rb
0.00 52.63 block (3 levels) in <main> - ../work/tmp/slow_search_parse.rb
0.00 52.63 block (2 levels) in <main> - ../work/tmp/slow_search_parse.rb
0.00 52.63 at_css - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/nokogiri-1.11.1-x86_64-linux/lib/nokogiri/xml/searchable.rb
0.00 42.11 <c function> - upto
0.00 31.58 require - /home/ilyazub/.rbenv/versions/2.7.2/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb
0.00 31.58 <c function> - unknown |
I was able to retrieve the type using bindgen, but I had to include several things (encoding.h, onigmo.h) to get it, and it's only available on 2.7.0 and newer rubies. Doesn't seem worth the added bindgen complexity, at least for now.
This works on Linux but fails on macOS because _global_symbols isn't available. The symbols _global_symbols.{0,1,2,3} are available but don't seem to work.
This also anticipates unit tests that will need to pass an arbitrary global symbols address.
590cbf3 to
7fe9ac9
Compare
|
the macos test failure here might be spurious, I've been seeing some failures on master too (at https://github.com/rbspy/rbspy/actions) |
|
@jvns I think this is ready. It works on 2.7.x for all three platforms, and back to at least 2.5.x on Linux. Support for older rubies may be possible with more effort. (Help wanted/welcome if anyone is interested!) Ruby 3.x is an important target, so I'll focus on that next. The failing macOS and Windows tests do seem to be spurious. I can repro them consistently on my laptop with asdf-installed ruby 2.7.2, but the tests pass consistently if I hack edit: I just remembered that FreeBSD support was added a while back. I'll give that a try tomorrow to make sure the build isn't broken. |
|
This looks awesome to me -- I'm happy to merge it whenever you say it's ready. The only thing I noticed is that it looks like the new ruby bindings were generated on a Mac (there's a bunch of Also, I've been adding people as maintainers when they make significant contributions (which this DEFINITELY is!!), so I'd be happy to make you a maintainer if you'd like! There aren't any responsibilities associated with being a maintainer, it just means you can merge changes and make releases if you want. Let me know :) |
|
Thanks! That sounds good to me. There are incremental improvements I'd like to make on C symbols support, and I'm happy to help out with code reviews and such.
Ah, good point. I haven't had any trouble with the updated bindings, but if we run into trouble I can regenerate them on Linux. CI looks happy, so I think we're good to merge. Thanks again for all your help with this. |
As noted in #110, rbspy currently lumps all C functions into a single bucket. It would be very useful to separate them so that we can understand which C functions are consuming the most time.
This PR is mostly a port of the print_id function from ruby's .gdbinit script, which takes a ruby method ID and returns the corresponding name as a string. The memory-walking logic is complex but has been very reliable in my testing so far.
I wasn't able to locate the global symbol table for 2.6 or older, so support is currently limited to 2.7.x (and newer, hopefully). It may be possible to expand this with more investigation -- I probably missed something. I haven't tried rubies newer than 2.7.2 yet.
Here's a sample from tracing a simple puma server when it's under load:
and when running
infinite.rb:I noticed that gdb is also able to print the raw C symbol name and its location in the source file. I don't know whether it's possible for rbspy to get that info, but it would be nice to have. Maybe the
remoteprocesscrate can do the symbol resolution part since we have the memory address.TODO
Fixes #110