Deploying to Production, Slowness, Versions, Lessons.
A story about deploying code to a production website. It’s not a disaster, and no customers got upset but I made our customers wait an extra second or two to load a page and that isn’t good.
Upgrading MySQL
I decided to upgrade MySQL on my Mac from 5.6 to 5.7 and that was my first mistake. The upgrade was smooth enough, but after I did it I realized that the production server was running 5.6 and it’s a nice idea to run the same version.
No matter, I’ll just install 5.6 again. I use Homebrew so I just uninstalled 5.7 and installed 5.6. Trouble is, I couldn’t get MySQL to start. Long story short: I ended up sticking 5.7. There’s a whole story right there but it’s not what I want to focus on. The relevant fact here is that I’m now running a later version of MySQL than production. More about that later.
Deploying Some Changes
Finally, I’m back to work and doing something productive. I’ve got some changes to a Ruby on Rails app I’ve been working on for a couple of days. I’ve been deploying to our staging server and it seems to work pretty well. I’ve got regression tests passing and everything seems to be working fine. The operations team are happy. Good… let’s put it in production.
A few minutes after I deploy I head over to New Relic to check out the change (I have a nagging suspicion that the page is a little slower). I quickly find out that the most popular page on the website (apart from the landing page) is now 10x slower and is responding in around 2,000ms (2 seconds). It used to respond in about 200ms.
Why did I just deploy code that was so slow?
- I didn’t do any benchmarking to see how slow the page was. I assumed that my Russian Doll Caching in production would speed the page up. I have caching in staging too but I wasn’t paying attention.
- I didn’t look carefully enough at the logs for the new page. If I had, I would have done something about the SQL that was scrolling past.
First Fix
Quick! Get some of this cached, right? I took the most expensive chunk of template and cached it as a partial, using an expiring key.
Second Fix
Over-enthusiastic caching! Some of my cached code changed depending upon the URL but I was just caching it all. I didn’t notice (at first) because my testing was to just reload the same page over and over. I noticed this once the first fix was in production. Fortunately, it was a quick fix: make the cache key include the relevant data to indicate the URL.
Third Fix
Okay, it’s all behaving itself again now but it’s still slow. I’ve shaved maybe 10% off which is an improvement but it still isn’t good enough. I had split a large template into a couple of partials and this gives me more information in the logs (time to render each partial). I’ve actually got an expensive piece of code that needs to be cached. Trouble is, that code changes depending upon whether you are logged in and who you are logged in as. Time for some ajax. I render the page as if logged out (the most common case) and then fire off an ajax call to bring back some JSON which describes how the code should be decorated. It’s a quick call (20ms) and means I can cache a large amount of code.
I like this pattern but you have to be careful. Your first-render of the code is going to be seen by the user, followed, shortly after we hope, the decorated version specific to that user. If that is going to look stupid or make the user think it’s broken then you need to rethink.
I deploy this code and we’re now down to just under 1,000ms. That’s great but we’re still slow! And, puzzlingly, I am getting quick responses on my Mac. I run some queries in the console (they are Rails scopes) and experiment with finding which bit is slow. I run the same queries on staging and finally it comes down to one scope that runs in 6ms on my Mac and 500ms on staging!
Bugger it. I realize I’ve been bitten by the MySQL version thing — there must be some difference between MySQL 5.6 and 5.7 that causes 5.7 to be a lot smarter about how it indexes that query.
The scope is actually a hand written piece of SQL with two nested SELECTs. I rewrite it by pulling out an array from one query and feeding that in as a parameter to the second. The array is only about 50 integers so we can handle that. The query goes from 6ms to 15ms on my Mac which is a shame but the good news is that it’s now also 15ms on staging (and production) too.
Here’s my original SQL in simplified code. Note: there’s a reason I’m not doing this with JOINS. It’s got nested SELECTs two deep :(
`SELECT a.id FROM a WHERE a.id IN (SELECT b.a_id FROM b WHERE b.id IN (SELECT c.b_id FROM c WHERE c.foo != ‘SKIP THIS’))`And here’s some pseudo-code showing the two step process which is a LOT quicker (in this particular scenario, YMMV):
b_ids = `SELECT c.b_id FROM c WHERE c.foo != ‘SKIP THIS’)`
`SELECT a.id FROM a WHERE a.id IN (SELECT b.a_id FROM b WHERE b.id IN :b_ids`Finally
We’re back down to 150ms page loads and we’re now running with a fancy new page that does lots of lovely things. Lessons I’ve learned and relearned:
- Measure stuff. Looks at the logs, look at the metrics (e.g. New Relic). Catching stuff just after it goes into production is better than waiting for your customers to tell you about it. Catching it before you deploy to production is even nicer.
- Be smart when you cache. Think about what can change inside the cache and make sure your key reflects that. Where possible, make the cache the same for everyone and decorate it afterwards.
- Run the same version of the database in development as you do in production. That goes to Ruby too. I’m still not sure whether I can get MySQL 5.6 installed actually but staging should help me cope with that.
- Turn on caching in development every now and again. Think about the impact.
