You should ignore garbage collection when optimizing performance locally. Here's why.
|
|
Recently, we merged a feature into rack-mini-profiler to ignore gc in flamegraphs. I think you should probably turn this setting on all the time in your development environment. Here's why.
When I start working with companies or doing a workshop, we always cover how to read a flamegraph. It's probably one of the most important, most foundational performance skills. If you know how to capture or read a flamegraph, you can solve almost any problem.
We usually capture these flamegraphs on a local development machine. This is useful, because you can change the code, reload the page and capture the flamegraph again, and see how the flamegraph changes.
The problem is: I almost always end up looking at a flamegraph with large amounts of time spent in garbage collection. Why is it that every controller action we profile, locally, ends up having large amounts of time spent in GC, far more than our production metrics say?
This ends up confusing my students, 80% of whom don't even understand when or why garbage collection occurs. That's the point of garbage collection - you're not suppose to think about it, it's supposed to Just Work!
How Garbage Collection Works in Ruby
First, you need to understand that the main expensive phase of garbage collection, sweeping (where we free up memory), occurs when either of these different thresholds are tripped:
- Object counts
- # of bytes allocated
There's a lot of detail here (is it the total number of objects? what about write barrior unprotected objects? old objects? oldmalloc or malloc?!? MINOR OR MAJOR GC?!?!?!) but I want you to be aware that either creating large numbers of objects (one million strings) or very large objects (a string with a million characters) will trigger GC.
The key point is that the limit for each of these thresholds changes over time. These limits start low, and each time we run GC, we increase the limit a little bit.
For example, when you start a new ruby process, the "total object" limit is 10000. Once you try to allocate the 10,001st object, GC triggers. After that GC though, the limit is no longer 10000. We increase the limit by the heap growth factor, which is 1.8 by default. So, the new heap will be allowed to have up to 18,000 objects.
So, there are about a dozen different thresholds in Ruby's GC, all of which work in this way: start low, grow as they are tripped and GC triggers.
The point of this kind of design is to keep memory usage of small programs low, and for big, long-running programs to run GC less often. Think about what would happen if these limits never increased and remained low: your Rails server would grind to a halt, as it would run GC 30 times during every controller action (controller actions typically allocate 300k objects or more!). On the flip side, if we just kept these limits all extemely high to start with, Ruby programs would use a lot of memory even if they just ran "hello world". So, it's a tradeoff.
How Garbage Collection Is Weird On Your Local Machine
There is a major difference between your local machine and a production Ruby process: your local process is very young, and your production processes are usually very old.
This means that your local processes have much lower thresholds for all GC triggers than your production process does. Production processes have processed tens of thousands of requests or background jobs, run GC hundreds of times, and had their thresholds raised quite high, which means the odds of GC on the next request are quite low. Locally, you haven't had any of that happen yet, which means that GC on the next request is quite likely (and, for the first dozen or so requests, basically guaranteed):
This means our local environment shows a quite unrealistic picture for GC frequency.
Now, there are two ways to fix this:
- Ignore it
- Run your profile 30+ times so that GC state stabilizes and your GC thresholds are more realistic.
When Should You Care about GC?
Now, ain't nobody got time to run their flamegraphs 30 times. Plus, it still leaves juniors and newbies to perf work confused - there's nothing telling them that the GC they're seeing in their flamegraph isn't meaningful. So, I think most of the time, you should just ignore it - and use rack-mini-profiler's setting to do so.
When you should care about time spent in garbage collection on your local machine?
- When your production metrics or flamegraphs tell you there's a problem. Most APMs (Scout, New Relic, Datadog) can all tell you when a trace or even aggregated traces are spending lots of time waiting on GC. If you're seeing it in prod, it makes sense to try to repro that locally.
- >1 million objects created during a request. Nowadays, Rails logs the number of objects created per request. If you're seeing that number consistently over a million, I would start paying attention to time spent in GC. Object creation leads to time spent in GC.
That's all for this week! Happy 2024 everyone.
-Nate
|
|
|
|