Hey, I upgraded Ruby to version 3 recently on our production server. When we upgrade to Ruby 3, many gems have to be upgraded at once, including Rails.
The request went from (before the upgrade):
Started GET "/dashboard/generated-receipts" for 127.0.0.1 at 2022-05-07 15:17:53 +0000
Processing by Dashboard::GeneratedReceiptsController#index as HTML
Rendering dashboard/generated_receipts/index.html.erb within layouts/drawer
Rendered dashboard/generated_receipts/index.html.erb within layouts/drawer (Duration: 33.4ms | Allocations: 18716)
Rendering layouts/application.html.erb
Rendered layouts/application.html.erb (Duration: 0.7ms | Allocations: 423)
Completed 200 OK in 43ms (Views: 39.9ms | MongoDB: 0.0ms | Allocations: 22192)
To:
Started GET "/dashboard/generated-receipts" for 127.0.0.1 at 2022-05-23 04:16:22 +0000
Processing by Dashboard::GeneratedReceiptsController#index as HTML
Rendered dashboard/generated_receipts/index.html.erb within layouts/drawer (Duration: 40.7ms | Allocations: 20943)
Rendered layouts/application.html.erb (Duration: 0.6ms | Allocations: 397)
Rendered layout layouts/drawer.html.erb (Duration: 47.4ms | Allocations: 23435)
Completed 200 OK in 1432ms (Views: 48.0ms | MongoDB: 1.4ms | Allocations: 24673)
(From 43ms to 1432ms !!!)
I don’t do anything besides fixing the interface incompatibility of Gems.
From what we see here, the view rendering time and object allocations did not increase by magnitude; it doesn’t look suspicious.
How can I find out, which part of the code is slowing down the request?
Does view rendering time include everything running during erb rendering? Or just the view-related code?
When we upgrade to Ruby 3, many gems have to be upgraded at once, including Rails.
I think it should be totally fine to upgrade Rails while staying on Ruby 2.7
Perhaps you could try to separate these upgrades to narrow-down the potential cause?
Hey,
Thanks a bunch for the reply.
We did pinpoint the issue, and it is not Rails. The only problem with Rails, if any, is that it is not clear to us what was included in the runtime report.
The problem is with Kaminari and Mongoid, and it is the other way around; it is not that it slow after the upgrade, but it is abnormally fast before the upgrade.
Turns out the older version of MongoDB driver performs an opportunistic optimization on count; this optimization was removed since Mongoid 7.2. To upgrade to Ruby 3, we need Mongoid 7.4.
The optimization read document count from the table metadata instead of performing an actual count when possible. Since Mongoid 7.2, the operation always performs count even with the entire collection.
And we have around 2.5M items in the collection.
It is not a trivial change for Kaminari; I guess we have to find some time to migrate to another pagination gem with more controls.
Sadly in this particular case, the slowness is in the database IO because it spent so much time waiting for the result. So most of the techniques are not applicable; also, we can’t isolate the chunk of code for benchmarking as it is Kaminari’s magic. Nor can we extract a reproducible code, as the slowness won’t appear in a small collection.