DTrace and Ruby on Rails with Leopard/Snow Leopard
Having just launched a major Ruby on Rails sports betting site for the French national lottery, there has been a period during which we’ve had to improve performance dramatically. While most of the benefits have been had by using a custom Rails middleware class there have been a number of actions that aren’t cacheable so I’ve needed to profile the request and then optimise some internals.
Fortunately starting with Leopard, Apple has included a patched version of Ruby that has DTrace probes support. DTrace is an awesome technology to receive tracing events when methods are started/finished etc. There is a lot more information about DTrace at sun.com if you want to know more.
How to trace a Rails request
By far the easiest way is to use script/server to fire up a Mongrel/WEBrick single process server and then attach DTrace to that. However, the problem is that if you’re trying to process an app as it normally runs then it will be in production mode, with lots of classes cached and maybe some stuff ready in memory. Therefore I wanted to do this by pointing DTrace to a currently running Passenger installation that I’ve pre-warmed.
Getting the PID of your Passenger process
The normal way I do this is to use passenger-status to get the PID of your Passenger worker process. You may want to restart Apache on your development machine in order to have it clean out all existing processes (you may have more than one) and then just use curl/wget to load a single request. An easier way might be to set the PassengerMaxInstancesPerApp Passenger Directive in your Apache configuration to 1 so you are guaranteed to only have one passenger process for the app.
Then you can use passenger-status to find out the PID of the child process:
Tracing a Request
Tracing a request is easy. You’ll need to download this dtrace script and then should fire up dtrace connecting to your $PID discovered above:
sudo dtrace -s rb_linetime.d -p $PID > log
Then in another window do:
curl http://my-local-domain/controller/action
When curl finishes you can go back to the first window and Ctrl-C to interrupt DTrace and your logfile will contain lots of lovely data to analyse. By going through this log, removing the lines in Rails code (we may be over-calling them, but a fair assumption to start with the assumption that it’s the time spent in our code that would be slow) we could then see the ‘big-hitters’ and work on them.
0 Comments so far
Click here to have your say...