Taking Out the Trash at RubyConf 2013
RubyConf 2013 was held in Miami and it was just as wonderful as always. In fact, I had the honor of speaking about effective debugging. But instead of writing again about speaking at a Ruby conference, I want to discuss one particular statement from RubyConf that inspired me.
Matz, during his opening keynote, first mentioned what became a recurring theme at RubyConf 2013: garbage collecting. In this case, garbage collection isn’t referring to a mark-and-sweep algorithm, but rather to the idea that, as Rubyists, we give back to the community by helping out. And sometimes, helping out includes taking out the garbage. For example, this could mean resolving bugs or building features for an existing library or gem that you use.
I was further inspired by Mark Bates’ excellent talk on Ruby 2.0’s TracePoint API, in which he claimed that Rails makes an astonishing 122,538 method calls. That many method calls to serve one HTTP request sounds insane, so I decided to do a little “garbage collection” of my own to see if there was an opportunity for me to give back to the community. Maybe there would be an opportunity for me to isolate and identify some inefficiency that would require a nice pull request to rectify.
My first task was to replicate Mark’s results, so I grabbed his code. After some hacking and getting comfortable with Ruby 2.0’s Tracepoint library, I had a little cold water to throw on the 122,538 method call claim: the overhead of running a Rails application in development mode accounts for a large part of this enormous method call count.
To get to the bottom of this discrepancy, I started with the lower limit by setting up a “Hello World!” Rack application. I determined that to process a single HTTP request made via command-line curl, 947 method calls are required to process the request. That’s only a few orders of magnitude away.
Next, I set up a “Hello World!” Sinatra app. It was a little tricky to ensure that the Tracepoint code played nicely with the Sinatra framework—the Tracepoint code had to be included before the Sinatra framework. Sinatra ended up clocking in at a respectable 4,375 method calls to process an HTTP curl request.
After setting up a “Hello World!” Rails app, I found that running in development there were only 79,073 method calls for processing one curl HTTP request.
I’m not sure what can account for the discrepancy of approximately 40,000 method calls for my experiment versus Mark’s presentation. Correction: In the comments below, Mark points out that he used Chrome so the 40000 less calls in my curl example is because curl doesn’t make subsequent requests for assets. He even showed a video of him creating a default Rails app, which is what I did as well.
However, I felt that using the development environment wasn’t a great comparison to Rack and Sinatra, as they don’t reload code on each request, like Rails does. It is more appropriate to compare Rack and Sinatra to running Rails in the production environment. There, I determined that Rails makes 15,136 method calls to process one curl HTTP request.
I couldn’t stop there, and went on to compare a curl HTTP request in Rails production (15,136) to a Google Chrome HTTP request (21,869). I attribute the discrepancy between curl and a web browser to the requests for assets. I also turned off turbolinks to see what the effect would be: only a few thousand fewer calls for a curl request (14,537).
At the end of this exercise, I had hoped to come away with a pull request that fixed some egregious inefficiency, but instead I’ve settled for a better understanding of the Ruby Tracepoint API, which should set the stage for my contributing more in the future. Even if I were to ignore all of the other benefits of attending RubyConf, I would consider this a good result. Sometimes taking out the trash may mean that I have to level up my skills!
Taking out the trash feels good. Feels real good. What garbage have you collected lately? And how has it made you a better developer?