At work, we were encoutering a few situations where Resque workers would hang indefinitely after forking. My first thought was to force the process to raise an exception in order to generate a stack trace which I would then be able to examine in the logs. However, sending TERM, INT, and QUIT signals to the process didn’t seem to have any affect. The process still hung, and I had nothing useful to look at in the logs. The only way to end the process was to send it a kill -9, which unfortunately means no stack trace and no clue as to what actually went wrong.

After this happened a few times, I realized that I needed to examine the running process for more information. My limited C/C++ exposure told me that gdb would be a great tool for this, but I wasn’t sure how I could get useful Ruby information after attaching to the running process. A little googling led me to an excellent blog post by Thoughtbot that included some helpful gdbinit definitions:

1
2
3
4
5
6
7

define redirect_stdout
  call rb_eval_string("$_old_stdout, $stdout = $stdout, File.open('/tmp/ruby-debug.' + Process.pid.to_s, 'a'); $stdout.sync = true")
end

define ruby_eval
  call(rb_p(rb_eval_string_protect($arg0,(int*)0)))
end

The first function redirects the process standard out to a temporary file which you can then tail -f in order to see what’s going on. The second function allows you execute arbitrary Ruby code inside the process. Assuming you have the above definitions in your ~/.gdbinit file, and a running irb process with pid 12345, the process would look like:

1
2
3
4

$ gdb /home/brandon/.rvm/rubies/ruby-2.1.0/bin/ruby 12345
(gdb) redirect_stdout
$1 = 20
(gdb) ruby_eval("puts caller.join('\n')")

Obviously, substitute your own path to the appropriate Ruby binary. In a separate window, you can tail -f /tmp/ruby-debug.12345 after the first command. The second command will then output the current execution stack for the running process. Your ruby_eval calls are running in the context of the currently executing code. So, for instance, you could see a list of currently defined local variables with Kernel#local_variables. You could then examine each of those variables in turn in order to get an idea of what was going on at that particular point in your code.

If you’re curious as I was about the call to rb_eval_string_protect() (which is an internal C function in the Ruby source), the first argument is the string of Ruby code that’s being executed. The second argument is an integer pointer to a defined error constant. In this case, 0 means the code executes successfully. A non-0 number would indicate an error, and the function would return nil.

These little gdb tricks have changed my world when it comes to debugging. I use this technique all the time.

If you enjoyed this post, please consider subscribing.