Slow requests in development are painful. They lead to slower feedback loops and decrease productivity. If you are working on a big Rails app, and you're encountering slow requests, especially after you make a change, there might be a simple way to make things fast.
I work on a decently sized Rails app at work (~450 models, ~400K LOC). One of the things I've noticed about it while working on it is that it feels very slow in my dev environment!
Often times, I chalk that up to how big the app is. But around 2 months ago, I started looking into it a bit more.
Now, I understand feedback loops like the ones we get while developing something in React or <insert fancy frontend framework> that has HMR might be too much too ask for. But the request times I was noticing still seemed a bit too high. And maybe, just maybe, something that can be improved.
One thing that stuck out, was that requests were significantly slower right after I make a code change (but only on the first request after a change).
There were pages which normally take ~600ms to load in development. But after I make a change to any
.rb file, the first request after that change takes a lot more (5-7s).
Curious as to what's causing the slowness, I fired up rack-mini-profiler and looked at the flamegraphs of the request.
I then compared the flamegraphs for a fast request vs a slow request (after a code change). And the slow request was certainly doing a hell of a lot more.
Some of the major extra things on the slow requests seemed to be related to reloading code (Zeitwerk) and reloading routes.
Now I am no expert on Zeitwerk and the magic it does, but I assumed maybe it's something that has to be done.
But reloading routes? Even when nothing related to routes changed? Surely, that has to be a weird application specific bug, I thought.
So I started looking into that. Maybe there's some arcane piece of code in our app (the app is ~10 years old btw) that reloades the routes?
And I did remember a middleware that did just that. But when I looked at it, it didn't seem to be the cause. It was properly configured to reload routes only when route related files change.
After going back to look at the flamegraph a second time and looking at what's invoking it, things appeared to point to something that's done by Rails itself.
And after browsing through a bit of the rails source, I found the culprit.
Specifically this block:
# Set routes reload after the finisher hook to ensure routes added in # the hook are taken into account. initializer :set_routes_reloader_hook do |app| reloader = routes_reloader reloader.eager_load = app.config.eager_load reloader.execute reloaders << reloader app.reloader.to_run do # We configure #execute rather than #execute_if_updated because if # autoloaded constants are cleared we need to reload routes also in # case any was used there, as in # # mount MailPreview => 'mail_view' # # This means routes are also reloaded if i18n is updated, which # might not be necessary, but in order to be more precise we need # some sort of reloaders dependency support, to be added. require_unload_lock! reloader.execute ActiveSupport.run_load_hooks(:after_routes_loaded, self) end end
What seems to be happening here is that when a rails application initializes, it's adding a block to reload the routes (
reloader.execute) whenever the rails reloader runs (
I am pretty sure the block you give to
app.reloader.to_run is executed whenever your code is reloaded (e.g on a change to one of your controller/model/view/etc files).
For example, if you changed a line in one of your models, Rails will reload your code and also run the block(s) you gave to
app.reloader.to_run on the first request after your change.
Here routes are reloaded through
RoutesReloader and it internally uses
ActiveSupport::FileUpdateChecker to watch certain paths and specify a proc that reloads the routes.
FileUpdateChecker has 2 methods that you should be aware of - called
execute. The former runs the proc only when the files watched by it have changed since the last invocation. The latter always runs the proc.
And if you read the comment, it says that it's intentionally using
execute rather than
execute_if_updated because we might be referring to constants in our route files. So whenever constants are reloaded, routes must be reloaded.
That might be an acceptable tradeoff for some, but in our case it was just too slow. We have a lot of routes, and as a result reloading routes takes a significant amount of time (~400-500ms to be exact).
To solve the problem above, I initially just patched the line in question above locally. Using
bundle open railties and then changing
reloader.execute_if_updated in the code inside the
I ran with that for a month, fully aware that it's just a temporary fix, and if I upgrade gems, the change will be lost.
And last week, because we started upgrading our ruby version, I had to reinstall gems and those changes were lost. Couple that with the fact someone else in the team complained about reloading speed last week, I thought it was time for a good ol' monkey patch.
From a quick look you'd think, we can just patch
execute method to instead be
However, if you do that naively, you'll break your app. Because, Rails loads the routes using
RoutesReloader#execute as well the first time the app is loaded (as you can see from the other
reloader.execute call in the code above).
So we'd want to patch
RoutesReloader after Rails has loaded routes during it's initialization phase (i.e after the
:set_routes_reloader_hook initializer above runs).
And because this is a dev-only thing we only need to do it in development.
Rails provides us with a way to define custom initializers that run after specific named initializers. All of this is documented here.
And here is the monkey patch. In all its glory:
# In config/application.rb module YourAppName class Application < Rails::Application ... if Rails.env.development? initializer(:monkey_patch_routes_reloader, after: :set_routes_reloader_hook) do class Rails::Application::RoutesReloader def execute execute_if_updated end end end end ... end
This simple change seems to have improved our reloading speeds significantly. Even though reloading routes take ~500ms, this actually seems to have lead to more gains than that. Perhaps because there's something reloading routes multiple times? In any case I'll take it 😀.
Requests after doing a code change before this patch took ~5-7s.
After this patch, it's down to ~3.5-4.5s.
One thing worth mentioning is that you can't rely on the duration of
Completed 200 OK in XXXms in your Rails log for this.
Those numbers don't seem to show any difference at all. If you instead check the "Network" tab in your Browser's DevTools and take a look at the time the request took, you'll see the actual numbers and the difference.
Lots of room for improvements in other areas still, but this was still a significant improvement IMO.
If you've got other ideas or questions, feel free to tweet at me @owaiswiz.