heroku-buildpack-ruby: Bootsnap cache incorrect or not being used?

Linked internal tickets

  • 952389

Issue

The bootsnap cache is present after a deploy:

$ heroku run bash
~ $ du -hs tmp/cache
64M tmp/cache
~ $ ls tmp/cache
bootsnap-compile-cache  bootsnap-load-path-cache

However if a rails process runs, the cache size doubles:

~ $ rails runner puts 'done' >> /dev/null
~ $ du -hs tmp/cache
125M  tmp/cache

And running the same command twice makes it faster, this makes me think that bootstrap isn’t being used:

$ heroku run bash
Running bash on ⬢ issuetriage... up, run.2775 (Standard-1X)
~ $ time rails runner puts "done"
# ...
real  0m7.197s
user  0m5.760s
sys 0m1.048s
~ $ time rails runner puts "done"
# ...
real  0m2.953s
user  0m2.384s
sys 0m0.492s

We need to investigate why. My first guess would be that the difference between build and runtime file structure prevents the original cache from being used. But that’s just a guess.

About this issue

  • Original URL
  • State: closed
  • Created 4 years ago
  • Comments: 25 (8 by maintainers)

Commits related to this issue

Most upvoted comments

@sergiopantoja @geoffharcourt Thank you for providing those timings - glad to hear it helped! It will be a bit longer before we can make this new behaviour the default, but that flag is fine to use in the meantime 😃

I’ve just added support for a beta opt-in labs build-in-app-dir, that makes the Heroku build system build in /app (the same location that the app will be run at runtime) rather than the previous location of /tmp/build_<hash>.

This can be enabled via:

heroku labs:enable build-in-app-dir -a <APP_NAME>

I’d be very interested to hear how much of a difference this makes to app boot times at runtime if anyone tries it out 😃

In our Rails app we reduced boot time from ~16 seconds to ~8 seconds after enabling build-in-app-dir.

Are there any caveats to be aware of?

Any progress to report regarding making this the default?

Theres’ a recent article about this as well that I want to link https://dev.to/dbackeus/cut-your-rails-boot-times-on-heroku-in-half-with-a-single-command-514d

Yes, though unfortunately since postdeploy runs after the initial build, enabling build-in-app-dir at that point will be too late (unless the script also triggers a rebuild, but that will require a bunch of manual wiring up, and also mean even slower provision times for review apps). At that point for many people I would imagine the slight loss of review-app to prod parity would be preferable to the workaround, particularly if they have a staging environment that can catch any rare build-in-app-dir related issues not seen in the review app. (Ultimately a review app is never going to be identical to production; datastore differences, load differences, env var differences etc mean that it’s only ever going to be mostly-similar at best.)

Just want to chime in that we are also seeing great results on our production app after enabling build-in-app-dir.

Before:

$ heroku run bash

$ time rails runner puts "done"
real	0m6.828s
user	0m5.844s
sys	0m0.904s

$ time rails runner puts "done"
real	0m3.072s
user	0m2.688s
sys	0m0.320s

$ time rails runner puts "done"
real	0m2.919s
user	0m2.500s
sys	0m0.372s

$ du -hs tmp/cache
32M	tmp/cache

After:

$ heroku run bash

$ time rails runner puts "done"
real	0m3.066s
user	0m2.664s
sys	0m0.336s

$ time rails runner puts "done"
real	0m3.132s
user	0m2.640s
sys	0m0.432s

$ time rails runner puts "done"
real	0m2.887s
user	0m2.512s
sys	0m0.304s

One problem we ran into and was able to address after identifying the issue is our app’s use of a third-party buildpack which cleans the slug after build (https://elements.heroku.com/buildpacks/devforce/heroku-buildpack-cleanup).

We had tmp/cache listed in .slugcleanup, which removed the folder before slug compression. Thus, the app was still experiencing “cold” boots. Removing the tmp/cache from the clean up config addressed the cold boot issue due to the tmp/cache folder now persisting in the compiled slug.

— Edit: One other thing to mention. The changes we made did increase the slug size by 10M (8% for our particular app). An increase is an expected result. Just wanted to share this detail.

After enable build-in-app-dir for Production, the boot up time went from 9.968s to 6.367s, which is (9.968 - 6.367) / 9.968 = 36.125…% faster

Before

# First time
~ $ bundle exec rake environment
real	0m9.968s
user	0m6.032s
sys	0m0.768s

# Second time
~ $ bundle exec rake environment
real	0m6.142s
user	0m2.640s
sys	0m0.368s

# Third time
~ $ bundle exec rake environment
real	0m6.045s
user	0m2.536s
sys	0m0.396s

After

~ $ time bundle exec rake environment
real	0m6.367s
user	0m2.748s
sys	0m0.432s

~ $ time bundle exec rake environment
real	0m5.997s
user	0m2.500s
sys	0m0.364s

~ $ time bundle exec rake environment
real	0m6.679s
user	0m2.704s
sys	0m0.328s

I just tried build-in-app-dir. Sadly, with no other changes, my build is hanging on rake assets:precompile. I filed an issue with support so it can be looked at.

@edmorley My boot time was cut in half! No issues so far. Thank you!

Before:

$ heroku run bash
~ $ time rails runner puts "done"
real	0m13.937s
user	0m8.328s
sys	0m0.988s

~ $ time rails runner puts "done"
real	0m6.512s
user	0m4.772s
sys	0m0.460s

~ $ time rails runner puts "done"
real	0m6.482s
user	0m4.860s
sys	0m0.432s

~ $ du -hs tmp/cache
94M	tmp/cache

After enabling the labs feature and redeploying:

$ heroku run bash
~ $ time rails runner puts "done"
real	0m7.150s
user	0m5.028s
sys	0m0.592s

~ $ time rails runner puts "done"
real	0m6.110s
user	0m4.672s
sys	0m0.388s

~ $ time rails runner puts "done"
real	0m6.171s
user	0m4.612s
sys	0m0.448s

~ $ du -hs tmp/cache
49M	tmp/cache