RubyProf, Oink and ActiveRecord bloat
There are some applications that are always gonna hammer the OS, I'm not talking about your common-or-garden web app, think huge amounts of I/O in the shape of huge file uploads, image processing, iso creation, hungry hungry hungry.
So what to do when you see ruby processes (spawned from passenger) gobbling up 1gb of RAM? The app was already in production so we had to be careful in our approach to profiling and code changes. Time to grab the production db and associated file data and see if the problem could be reproduced locally.
I'd say this is the hard part of profiling, where to start looking in a fairly large in-production app? A bit f common sense helped here, we knew that there were some expensive processes mainly dealing with large amounts of image processing and large amounts of copying files. My very experienced colleague pointed me at this article detailing common mistakes made when developing with active record.
So a quick search through the codebase for all.each and find(:all as mentioned in the article lit up some hotspots in the app code where potentially we could be experiencing bloat.
Next step was to wrap these code blocks in a ruby profiler block as detailed here then make the app execute the profiled code block - no changes to the code yet - this is just to get a benchmark.
Now we made a small but apparently very important change removing a programmatic filter on a large collection (one of those all.each... buggers) and swapped in a more precise active record find with conditions and some outer joins to get us the desired collection. The app was restarted and the same test run again leaving the profiling block in place and bingo processing time was one sixth of the previous run, big improvement in changing 4 lines of code.
But all this was done in a local production copy, we needed verification of what was causing bloat in production, adding profiling to production was a risk we couldn't take but what we did do was add and configure the oink gem which gave us a memory stat in the production logs and after a few hours of normal app use the ability to do $ oink -t 50 log/production.log which gives the insightful output:
---- MEMORY THRESHOLD ----
THRESHOLD: 50 MB
-- SUMMARY --
Worst Requests:
1. Dec 02 11:11:08, 143136 KB, BarController#foo
so verification of the bloat as this method was executing the all.each mentioned above. All the evidence was converging on this point in code. Marvellous!
I had never profiled a Rails app before admittedly this was not your average app but the tools used here definitely took us from hunches and presuppositions to good solid evidence and the beginnings of some simple but effective performance refactorings.
Hope it helps you when your 400lb Gorilla app starts playing up.