Doing a big activerecord query with a lot of peripheral objects.
Adding ".includes" (preloading) speeds it up dramatically by squashing all the N+1's.
The page then renders fast and spits this out into the logs:
Completed 200 OK in 504ms (Views: 104.2ms | ActiveRecord: 86.0ms)
However, it is then * 90 SECONDS * until the page is actually sent down to the browser (or curl; we've tested with both).
During which time the ruby process has the CPU pegged at 100%.
If we remove the ".includes" (preloading) it goes back to normal crappy performance without the minute-and-half chasm of nothingness between page render and browser delivery.
WTF does the preloading cause that after effect!?
One colleague has hypothesized a garbage collection issue; how might I test that theory?
Rails 3.2.12
Ruby 1.9.3 (p286 and p327 tested)
Found the problem; it was the Bullet gem (https://github.com/flyerhzm/bullet).
This gem cleverly finds and reports on N+1 queries and overzealous includes, but in the case of very large result sets it bogs down the application performance considerably.
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With