How do you view a sample of the call stack in ruby?

Question

I'm investigating different optimization techniques, and I came across this post Analyzing Code for Efficiency? by someone who believes that sampling the call stack is more effective than using a profiler. The basic idea is that if you take a view of the call stack, you see where your application is most likely to be spending most of its time, and then optimize there.

It is certainly interesting, and he is obviously an expert on this, but I don't know how to view the call stack in ruby. In debugger I can say "info stack" but only seems to show one line.

EDIT: I saw this comment by Mike Dunlavey: "I would just like to point out that if you run under the debugger, interrupt it manually, and display the call stack..."

I'm just not sure how to interrupt it manually and dipslay the call stack.

Solution 1

Just put

puts caller

anywhere in the code. If you don't like its format, it's an array of strings, so you can do some regex manipulation for a desired output.

Solution 2

How about sending signal to the ruby process, and creating a handler for the signal which dumps all stacks?

From http://le-huy.blogspot.com/2012/04/dump-backtrace-of-all-threads-in-ruby.html we have this example :

require 'pp'

def backtrace_for_all_threads(signame)
  File.open("/tmp/ruby_backtrace_#{Process.pid}.txt","a") do |f|
      f.puts "--- got signal #{signame}, dump backtrace for all threads at #{Time.now}"
      if Thread.current.respond_to?(:backtrace)
        Thread.list.each do |t|
          f.puts t.inspect
          PP.pp(t.backtrace.delete_if {|frame| frame =~ /^#{File.expand_path(__FILE__)}/},
               f) # remove frames resulting from calling this method
        end
      else
          PP.pp(caller.delete_if {|frame| frame =~ /^#{File.expand_path(__FILE__)}/},
               f) # remove frames resulting from calling this method
      end
  end
end

Signal.trap(29) do
  backtrace_for_all_threads("INFO")
end

Then we need to send the signal to the appropriate process :

ps afxw | grep ruby
kill -29 <pid>
ls -l /tmp/ruby*
vi /tmp/ruby_backtrace_...

Repeat the signal at appropriate sampling time.

Solution 3

You can throw an exception at any time, and then look at the $@ predefined variable, which returns an array of backtrace data. E.g. put this in foo.rb:

begin                                                                        
  raise 'foo'                                                                
rescue                                                                       
  puts $@                                                                    
end  

Then run it:

$ ruby foo.rb 
foo.rb:2:in `<main>'

Comments

[Phil Frost]

Isn't sampling the stack precisely what many profilers do? Look at stackprof, for example.

[d11wtq]

Does this work in the context of performance optimization? If the idea is to see a stack trace at a point when the application is running slowly, it seems like you have the catch-22 situation of knowing where the bottleneck is, in order to add this code at the correct spot?

[Mori]

@d11wtq, The idea is to run your app between begin and rescue, and hit Ctrl-C when the app is slow. That will tend to land on the thing that the app spends most of its time doing. Optimizing that will give the most bang for the buck.

[d11wtq]

Ah, ok thanks. When I do that in 1.9.2. I just get Interrupt and a stack trace regardless of the begin..rescue block. Where does the begin..rescue block come into play when the process is terminated with a SIGINT? I fear I may be being a bit blonde here o_O

[Andrew Marshall]

p caller or puts caller.inspect will give you a nicer output format.

[Nakilon]

No need of .join("\n")

[antinome]

This doesn't seem to answer the question. Printing the call stack at a specific point in your code can be useful, but it is not a random sample. It won't tell you what's on the stack at a randomly-chosen points in time.