A Journey to Optimization

Recently I had the task of optimizing a notoriously slow page (an average of 14 - 16 seconds on Heroku) on a project that was about to go live. In the past, I was able to get the load speed down a little but there was still room for improvement. For me, optimization had never been difficult/necessary as most of the projects I worked on had relatively small datasets, but that was not the case for this project. Taking the advice of a co-worker I did two things: started implementing caching and adding a gem called rack-mini-profiler.

I started with caching, but looking back I should have started by adding rack-mini-profiler. If you don’t know about the gem rack-mini-profiler I recommend taking a look even if you might not need it. It is a lightweight gem that displays speed badges for every html page. These badges can be expanded to view SQL times and page load speeds. This tool is great for locating and understanding bottlenecks in projects. I will be using it on every project I work on going forward.

First Attempt

At this point I was attempting to optimize the load speed using low-level caching, however I did not have rack-mini-profiler setup yet so I was only trying to fix/optimize what I thought were the bottlenecks. After reading some documentation on low-level caching I came up with a solution to test. Below is a snippet of this code, which is pretty simple.

@country_demands = Rails.cache.fetch(['country_demand', "#{@years.to_s}"]) { CountryDemand.where(year: @years}

Unfortunately this piece of code provided no improvements to the load speed, and once I verified that I had actually used the cache with no benefit, it was back to the drawing board for me. At this point it was time to install rack-mini-profiler to help discover more about the bottlenecks. This was when I realized there were about 2400 SQL queries that were being fired after the page load, which was an immediate red flag to me.

Second Attempt

Once I dug down into the code, I found a few association calls being made in partials being rendered that were causing a n+1 problem. After discovering this I knew I could improve the load speed, so I added some includes calls to the Country Demand query and set out to test the load speed again.

@country_demands = Rails.cache.fetch(['country_demand', "#{@years.to_s}"]) { CountryDemand.includes(:purchase_order).includes(:application).where(year: @years}

With the includes added to the caching logic I was able to get the load time to around 8 - 9 seconds on Heroku. At this point I realized that most of my speed (if not all) had come from the includes and not from the caching like I had thought. Since I had added includes to a few SQL queries before this should have been the first place I looked when trying to optimize this page, but because of the complicated view I was generating I overlooked this as an option (and since I had already added some I didn't think I missed any) when I revisited optimization. After achieving the new load speed, it was time for me to confirm where the speed actually came from, which would involve testing the code with caching and without caching. As expected, the real speed was achieved from the includes and the caching was actually providing almost no improvement, so with that in mind I removed the caching code.

Final Changes and Thoughts

Once I confirmed the improvements to the load speed, I wasn’t sure if I would be able to get any more performance boosts out of the page. However, I remembered that I had gotten a little performance boost when I removed a partial call. Looking at rack-mini-profiler I could see all the partial calls being made, which were a lot but none that were taking too long, however I still wanted to see if it could make a difference. The partials that I set out to remove were put in place to help organize the code because of the complexity of the view. After removing the partial calls and putting their code into the corresponding places I was able to achieve a new load speed of around 4 - 6 seconds on Heroku.

With all these changes in place I was satisfied with the load speed and ready to push to Production. At the end of the day I started out with an average load speed of about 15 seconds and ended with an average of 5 seconds. Looking back I wish I had done a few things differently. The first being that I wish I had installed rack-mini-profiler from the start, because blindly trying to optimize a page was a bad idea. This led me down paths where I was adding code that was not necessary and may have done more harm than good in the end. Also going forward I will be making sure to add includes (eager loading) to any page that may be SQL intensive.
Picked by Scott
Sep. 16 2016