Re-visiting my Gigglr project that I built before Flatiron has been an eye-opening experience. While I built this only 7 months ago, it’s amazing how obviously bad my code was back then. It’s a little embarrassing looking back at this project, but I’m pleased with the growth I’ve made that enables me to see all the mistakes I made back then.
One of the mistakes that leaps off the page is how pages require redundant(N+1) database queries. When I initially built Gigglr, database calls felt free. Now I understand how excessive database calls can increase server costs and page load time. Increased production costs and slow performance is a lose-lose for both developers and users.
Scrolling through development server logs can provide a basic understanding of how many database queries are running for each page, but it’s just not detailed or organize enough. That’s where New Relic comes in.
New Relic, a leader in application performance monitoring, offers a free Ruby gem for monitoring performance. Using the gem for a real production application will cost you, but we can get a lot of value out of it for free in development.
The New Relic gem works by monitoring each controller action for database queries, asset loading, load times, and more. These details are then saved in a report you can access at http://localhost:3000/newrelic or whatever URL you’re running your local server at plus “/newrelic”.
As you can see, it provides page response time, the URL, and how many SQL queries. Drilling down further into the Details gives us more information on that action with a pie chart and list of each SQL query.
Let’s get to work on Gigglr. Looking over my report, there is one controller action that is embarassingly bad.
Ugh, 67 queries for the Comedians index! This is unacceptable. Let’s get this down as much as possible.
Opening up the detailed SQL query list we see 20 queries that look like this:
Seems like this query is happening so we can display how many fans each comedian has. We’re rendering 20 comedians so the current set up requires 20 database queries. I suspect this is the offending code:
Just to confirm this is the offending code, let’s remove this line from our view and see what happens.
Well that’s surprising. Our SQL queries went up! There must be something else going on.
Another possible culprit is our Comedians Index controller action:
This code sorts in Ruby which is generally a bad idea. We’ll ignore that problem for now and outright delete the sorting.
Applying both these tweaks reduce our SQL queries to 47.
Now, the problem is we still want to sort comedians by how many fans they have, and we want to display their fan count. The easiest way to accomplish this without making too many queries is to simply add a “fan_count” column to the comedians table.
Note that we’re executing a SQL update statement to update all the comedians with their current fan count.
The next thing to do is set up the create and destroy relationships actions to update a comedian’s fan count whenever a user follows or unfollows them.
Now we need to be re-implement sorting by fan count and displaying the fan count.
A quick test confirms that our sorting and fan count display work again and our SQL query count is still at 47. Perfect!
47 is still way too many so let’s find the next thing to optimize. Here’s a snapshot of our current SQL query list:
Looks like we’re pulling a lot one-by-one from the shows table:
The obvious suspect here is the code below that pulls the next 3 shows for each comedian.
Sure enough, removing this code from our view drops the SQL query count to 27.
This is a classic case of the N+1 Problem where as we iterate over each comedian, we’re also querying their shows. To solve this, we’ll need to use “includes” on our comedians query like so:
Note that we’re including a condition that we only want shows with a showtime after today’s date. We also need to pass a shows reference whenever a condition is used. If we wanted all the shows, we could just use:
Okay, we’re displaying our shows again, and we’re all the way down to 22 queries! Here’s what the SQL log looks like now:
There’s still one more redundant query we need to eliminate:
The guilty party is our helper method that relies on a User method called fan_of? to render the appropriate form for following or unfollowing comedians.
The fan_of? method is the real culprit here. The fan_of? method has valid uses in other parts of the application so I don’t want to change it right now. A simple solution for this problem exists anyway.
To resolve the issue, I’ll do 2 things.
- Add users to our includes call in the comedians controller
- Update the comedians helper to use include? instead of fan_of?
With those 2 changes, our SQL count drops to 6!
We could certainly optimize this further, but I’m satisfied with 6 calls for now. Besides, the Shows Index action is now the most query heavy with 18 SQL queries. Better work on reducing that before we further optimize the Comedians index action.
It’s a truly eye-opening experience seeing how easy it is to make excessive SQL queries. I love Rails, but the downside of it is that the magic of it presents a lot of situations where the N+1 Problem rears its ugly face. Now that I know how to use tools like New Relic, I’ll be sure to keep these in check in the future.