Coding in the Crease

At TST Media we upgraded our NGIN application from Rails 2.3.2 to Rails 3.0.5 on April 6th. Unfortunately, we immediately saw the average response time of our application double. NGIN running on Rails 2 had an average response time of 300 ms per request with a throughput of around 1750 requests per minute. Running on Rails 3 with similar throughput levels, the average response time was around 650 ms per request. We have since reduced this down to just under 500 ms per request by tuning our garbage collection settings through Ruby Enterprise Edition (REE), the details of which deserve a separate blog post.

Comparing average response times between days can be tricky since there are many variables. The first one to consider is the amount and type of traffic. As traffic increases, average response time typically increases as well. The following charts show the throughput in requests per minute to be very similar.

Throughput levels were around 1500 requests per minute (rpm) at 8 am and rose to 2000 rpm on the 5th, whereas on the 6th it only reached 1800 rpm by 11 am. So the amount of traffic was slightly less on April 6th. The type of traffic NGIN receives can also account for major changes in response time. We carefully considered this as a possibility, but we found there to be no significant change in the type of traffic received.

The next thing we looked at is whether or not the change in performance was due to a single feature or a single action. Sometimes a single action can skew an application's average response time. Using New Relic's Web Transactions tab we were able to compare the performance of several key actions within NGIN. The table below shows performance data for four of the more frequently called NGIN requests. It is clear that the performance of each of these was significantly impacted with the upgrade to Rails 3. The performance difference did not appear to be due to a single action, but instead was affecting everything.

Upgrading to Rails 3 was much more than just upgrading Rails. NGIN depends on 60 gems and 9 plugins. Most of these gems and plugins were upgraded during this process as well. With this in mind we were hesitant to immediately blame Rails 3 itself for the performance degradation. However, considering the points made above that show that the performance of everything has degraded, not just a single feature-set, a quick scan of our gems and plugins turned up only two gems that could possibly affect the performance of NGIN across the board. Those gems are mysql2 and multi_db. On Rails 2 we used the mysql gem and during the upgrade to Rails 3 we switched to the mysql2 gem. We use multi_db to spread our sql read requests out to multiple slave databases, and we upgraded the multi_db gem ourselves to work with Rails 3. At this point I was farely confident the performance degradation was due to either Rails 3, multi_db, or mysql2, and to determine which one would require getting my hands dirty and running some simple benchmarks.

I'm not sure why the performance of Rails 3 is not a hotter subject. Initially Rails 3 ActiveRecord was 5 times slower than Rails 2, but with some nice work by Aaron Patterson (tenderlove) on optimizing AREL, this difference was improved greatly.

Otherwise the only other relevant post I've found, by Bill Harding, had similar results as NGIN, meaning Rails 3 was twice as slow as Rails 2 until tweaking REE's garbage collection settings.

At this point I decided to finally dive in and run some basic benchmarks. The simple benchmark below loads 10,000 User ActiveRecord objects from the database.

With Rails 2 it takes about 6 seconds to load the 10,000 user objects. I am saving the user off in a local variable and accessing the user_name field for consistency. This is necessary for the Rails 3 benchmark to guarantee that the database is getting hit by the User.where call, which would otherwise not execute the sql query due to AREL's lazy sql execution.

Running the same benchmark with Rails 3:

The difference here is astounding! With Rails 2 it takes around 6 seconds to load 10,000 User objects, and with Rails 3 it takes around 12.6 seconds, over twice as long! Interestingly, the preferred where syntax with Rails 3 is slightly faster, coming in at 11.5 seconds, which is still roughly twice as slow as Rails 2.

The performance difference with this simple benchmark, Rails 3 being twice as slow as Rails 2, corresponds very closely to the performance difference we saw with NGIN on upgrading to Rails 3.

To make sure that the change from the mysql gem to mysql2 did not account for the performance degradation, I ran this same simple benchmark with the mysql gem instead of mysql2 gem. There was not a noticeable performance difference. I did the same for multi_db, which also did not have a noticeable performance difference with this simple benchmark.

Simplifying a problem down to only what is needed is an extremely useful technique. Getting rid of all the cruft that is not necessary to demonstrate a problem is useful in understanding the root cause of an issue, and is an excellent way of creating something that can be reproduced by anyone.

In this case, the cruft around my simple benchmark above is the NGIN codebase itself. I created two new rails projects, one for Rails 2 and one for Rails 3, which includes an empty User model and some migrations to create the User table and populate the User table with 10,000 users. Clone this repository and follow the steps in the README to run this benchmark yourself: https://github.com/tstmedia/simple_benchmark

Interestingly, running this simple benchmark outside of NGIN in a clean rails project had significantly different results. Rails 2 loaded 10,000 User objects in 3.7 seconds, and Rails 3 took 5.3 seconds.

So in this case, Rails 3 is 1.43 times slower than Rails 2. While still significantly slower than Rails 2, it is not as bad as the 1.88 times slower when run within the NGIN codebase. I have yet to figure out what is causing this difference, but I expect it is a combination of things instead of a single culprit.

All of the above benchmarks were ran on our staging environment, using REE 2011.03, which is Ruby 1.8.7 patchlevel 334, and MySQL 5.1.55. Interestingly, when I ran the simple benchmark outside of the NGIN environment on my MacBook, Rails 3 was only 1.2 times slower than Rails 2.

At this point it is clear that the blame for the performance degradation goes to ActiveRecord. In a real-world application, ActiveRecord 3.0.5 is twice as slow as ActiveRecord 2.3.2. In a simple benchmark within a clean rails framework it is 1.43 times slower. Clearly the benefits of Rails 3 pale in comparison to this major performance difference. If you are considering upgrading to Rails 3, I would suggest waiting.