Troubleshooting - rails env has inconsistent load time



Caveat: I tried for a minimal reproducible error case that exercised the rails env. A more complex use case is at the bottom and affects rspec.

- run: bin/rails r "puts 'foo'" takes a highly variable amount of time on CircleCI 2.0.

Local laptop result: 16s-21s consistently, including cold cache.

15 container results (3 builds @ 5 containers each):

No ruby/rails commands had been run in the container prior to this point. Gems were restored from cache and DB was restored from cache and loaded with pg_restore.

Note that I consider the 22s containers to be perfectly expected. The 50s+ containers are my worry (3xlocal!). We run a variety of builds across multiple containers and that potential 30 seconds added on to each rails related command we run gets onerous when it’s a per container cost.


Related (probably) issue is that rspec taking a very long time for loading files:

From Circle logs:
Finished in 1 minute 31.1 seconds (files took **1 minute 47.31** seconds to load)

From local with same build command/set of files (spring disabled - no preloaders involved):
Finished in 1 minute 48.98 seconds (files took **16.06** seconds to load)

Note to Circle employees - happy to provide a link to private builds if it’d help.


I did some deeper diving on this and would be curious for another opinion on some of my findings.

I verified that the slowdown is under config/environment.rb specifically where it loads
require File.expand_path('../application', __FILE__)

The boilerplate Bundler.require(*Rails.groups) line was responsible for the lion’s share (~40 seconds) of the load time, just to really drill in the point that this is an issue with being slow to load gems.

To get more granular data, I overrode require and collected timing data on loading application. I’ve grabbed the top 15 files that differed the most in load times:


As you can see, the difference is spread across many different gems at different layers of the stack, each one being slowed by a decent amount.

Why would gems be loading slower in one container vs. another? This is a run of the same job across 5 containers. Each runs the exact same load, no smart splitting going on while isolating this analysis.

Edit: just to be explicit, I am fully aware that higher level requires will aggregate the runtime of lower level requires and double count. I’m being very cautious in comparing apples to apples between runs.


This topic was automatically closed 41 days after the last reply. New replies are no longer allowed.