Tip: Debugging slow Heroku builds
It’s always best to follow a systematic approach when trying to speed up slow code.
First, measure the current performance.
Next, make the change that you think will help.
Lastly, measure again to see if the change worked.
It’s no different when it comes to debugging slow test suites or deploys.
I recently noticed that my Heroku deploys were taking nearly 10 minutes to build.
Thanks to a tip from my friend Anthony, I was able to quickly measure, diagnose, and deploy a fix that shaved nearly 4 minutes off every Heroku build. Big win!
Heroku uses “buildpacks”, which are essentially shell scripts that run to install and configure your server.
But even if you watch the build log as your code changes deploy, there aren’t many affordances for knowing what parts of the process are slow.
You can add this buildpack to your Heroku app and it will output timestamps of each step in the process.
2021-05-10 19:30:59 2021-05-10 19:30:59 -----> Creating runtime environment 2021-05-10 19:30:59 2021-05-10 19:30:59 NPM_CONFIG_LOGLEVEL=error 2021-05-10 19:30:59 YARN_PRODUCTION=true 2021-05-10 19:30:59 NODE_ENV=production 2021-05-10 19:30:59 NODE_MODULES_CACHE=true 2021-05-10 19:30:59 NODE_VERBOSE=false 2021-05-10 19:30:59 2021-05-10 19:30:59 -----> Installing binaries 2021-05-10 19:30:59 engines.node (package.json): unspecified (use default) 2021-05-10 19:30:59 engines.npm (package.json): unspecified (use default) 2021-05-10 19:30:59 engines.yarn (package.json): unspecified (use default) 2021-05-10 19:30:59 2021-05-10 19:30:59 Resolving node version 14.x... 2021-05-10 19:31:00 Downloading and installing node 14.17.0... 2021-05-10 19:31:01 Using default npm version: 6.14.13 2021-05-10 19:31:01 Resolving yarn version 1.22.x... 2021-05-10 19:31:01 Downloading and installing yarn (1.22.10) 2021-05-10 19:31:02 Installed yarn 1.22.10 2021-05-10 19:31:03 2021-05-10 19:31:03 -----> Restoring cache 2021-05-10 19:31:03 - node_modules 2021-05-10 19:31:05 2021-05-10 19:31:05 -----> Building dependencies 2021-05-10 19:31:06 Installing node modules (yarn.lock) 2021-05-10 19:31:07 yarn install v1.22.10 2021-05-10 19:34:10 Done in 191.01s. 2021-05-10 19:34:10 2021-05-10 19:34:10 -----> Caching build 2021-05-10 19:34:10 - node_modules 2021-05-10 19:34:17 2021-05-10 19:34:17 -----> Pruning devDependencies 2021-05-10 19:34:17 Skipping because YARN_PRODUCTION is 'true'
I added this buildpack to my staging Heroku app and was able to pinpoint the hot spots in the process. My findings showed that running
After identifying the troublesome build step, I decided to turn on the
--verbose flag for
yarn to see why things were so slow. The official
nodejs buildpack is supposed to automatically cache
npm packages so it was strange that every build was spending 4 minutes installing.
--verbose flag generated a huge amount of extra detail to help me find the problem – over 23k lines of logging…
Downloading binary from https://github.com/sass/node-sass/releases/download/v4.13.1/linux-x64-83_binding.node Cannot download "https://github.com/sass/node-sass/releases/download/v4.13.1/linux-x64-83_binding.node": HTTP error 404 Not Found Hint: If github.com is not accessible in your location try setting a proxy via HTTP_PROXY, e.g. export HTTP_PROXY=http://example.com:1234 or configure npm proxy via npm config set proxy http://example.com:8080 Building: /tmp/build_496d129f/.heroku/node/bin/node /tmp/build_496d129f/node_modules/node-gyp/bin/node-gyp.js rebuild --verbose --libsass_ext= --libsass_cflags= --libsass_ldflags= --libsass_library=
Buried deep in the logs was the culprit. We were trying to download a pre-compiled
node-sass binary, but it wasn’t found (because Heroku was running Node 14 and the version we asked for was only built for Node 10). After timing out, we then built the native package manually. Aha!
(The fix was to update
While this fix was specific to my project, the process is generalizable: measure your Heroku build to find the slow parts, then dig deeper until you can find the underlying problem.
If you find yourself waiting and waiting for your Heroku builds to finish, try adding this buildpack so you can debug why it’s slow.