Skip to content

357 Seconds per Push, and the Tests Were Not the Problem

Our pre-push gate took almost six minutes. The container read the repository through a bind mount, and that alone accounted for 324 of the 357 seconds.

Patrick Lehmann
6 min read
One suite, two runs: 324 seconds when the files arrive over a bind mount, 21 seconds when they sit in the container.

Every git push in our monorepo first runs a gate: a Lefthook hook that starts exactly the checks CI would run afterwards anyway. A red pipeline you learn about by mail twelve minutes later costs more time than a minute of waiting on your own machine — that is the entire argument for having one.

That gate had grown to 357 seconds. Almost six minutes, on every push, even when the change was a single corrected line in a Markdown file.

On 25 August it was bypassed twice in a row with --no-verify. That was the real problem. A red run is annoying; a gate you get into the habit of skipping protects nothing at all.

Measure first

The first suspect was the test suite itself. Ours is a contract suite under tests/ci: a set of Python tests that check, for every change, that the deployment configuration, the CI definition and the infrastructure templates still agree with each other. The second suspect was the container setup — the suite runs in python:3.12-alpine and installs its dependencies there on every run. A prebuilt image was on the plan as the headline fix, along with three other ideas.

We measured them before implementing any of them: instrumentation in the gate, phase markers inside the container, one report per run.

The prebuilt image was dead after a single run. apk and pip together cost 4.0 seconds. Building an image, pushing it to a registry and keeping it current is more work than that is worth. Parallelisation fell for a related reason: most pushes start a single job anyway, so there is nothing to overlap.

What actually worked was not one of the four items on the plan.

— From the measurement log

Not the tests — the reading

The phase markers pointed somewhere none of the planned measures would have touched. The suite itself, 1099 tests across roughly 70 modules, was fast. Reading the files was slow.

Same suite, same image, same machine:

Where the container reads fromRuntimeFactor
A bind mount of the repository324 s15.4×
The container's own filesystem21 s

The profile had no hotspot: no single slow module, no expensive query, no runaway loop. Instead there was a flat tail spread across all 70 modules, with system CPU time roughly equal to user CPU time. That is the signature of per-file syscall latency, and it is the worst case for virtiofs under Docker Desktop for macOS.

The conclusion was inconvenient but unambiguous: if reading through the mount is expensive, the container must not read through the mount.

Streaming a tar instead of mounting

The repository is no longer mounted. It is streamed into the container: git ls-files produces the file list, tar packs it, and docker run -i receives the stream and unpacks it into the container’s own filesystem.

git ls-files and explicitly not git archive HEAD. The gate also gets invoked by hand against a dirty working tree, and a gate that quietly checks the committed state while you are looking at uncommitted changes is precisely the failure it exists to prevent.

Three flags on that tar are load-bearing, and each of them cost us a failed run to find:

FlagWithout itWhy it was hard to find
--format=gnutarbsdtar writes pax headers by default, and busybox folds them into the file contentsThe symptom is 282 UnicodeDecodeErrors in tests that read perfectly ordinary source files. Never a tar error. It looks like a broken suite.
--no-recursiontar descends into any directory you hand itgit ls-files reports the gitlink accounting as a directory. Without the flag, a second repository ends up in the stream.
-s (rewriting .git)In a worktree, .git is a file containing a pointer, not a directoryThe substitution runs before tar strips the leading slash, so the pattern has to start with a slash or it never matches.

Result: 357 seconds down to 61 seconds. Same suite, same scope, not one test skipped.

The remaining 61 seconds

At 61 seconds the question changes shape, so we measured once per kind of change:

Kind of changeTotalComposition
Repository root only61.5 sContract suite alone
Client website61.5 sWebsite tests 1.1 s + contract suite 60.2 s
Frontend application138.6 sFrontend tests 54.3 s + E2E 23.1 s + contract suite 60.9 s
Rails application252.1 sRSpec 192.4 s + contract suite 59.5 s

The interesting row is the second one. Change a single line in a client website and you wait 1.1 seconds for that website’s tests and 60.2 seconds for a contract suite that cannot possibly be affected by the change.

The obvious fix is path mapping: only run the contract suite when certain directories are touched. We had exactly that, and we deleted it on 26 August because it skipped silently. A gate that says nothing when it passes also says nothing when it checked nothing.

Then the cache spoke up

What was left is the most common case in daily work: the same tree, checked twice. A push after a rebase that changed no content, a second attempt after a rejected push, a git push immediately after the last run.

For that the gate builds a fingerprint of the working tree: HEAD, the index, the status, and the hashes of the dirty paths. Computing it costs 0.578 seconds. If the fingerprint is known and the suite passed against it before, the suite is skipped: 1.3 seconds instead of 63.2.

Four rules keep the cache honest:

  • Only hermetic suites are cacheable. Anything whose result depends on something outside the tree runs every time.
  • Only passing runs are recorded. A failure says nothing about the tree.
  • Entries expire after seven days. The tree is not the whole input: base images and toolchains change without any file changing.
  • There is an off switch. GATE_NO_CACHE=1 forces the real run, and anyone measuring needs it.

The most important part is in none of those rules: a cache hit prints a line. It says that nothing ran here, and how much time that saved.

The report had to follow for the same reason. A cache hit first appeared there as an ordinary 1.3-second run. The number is correct and still claims something false. Today the report lists hits in their own column, with a footnote saying that this row measures how long the skipping took, not the suite.

An aside: a threshold nobody ever checked

Instrumenting the gate turned up something unrelated to speed. A coverage configuration set fail_under = 100, but the final report ran without the matching environment variable. The threshold sat there and was never enforced. Since when is no longer reconstructable.

The moment it became active, the gate failed — on a genuinely uncovered branch: the warning that a runner reports more cores than it actually enforces. Not a freshly armed rule being pedantic, then, but a real gap that a broken configuration had been hiding. One fixture test later: 1099 → 1100 tests, 99% → 100%.

Conclusion

Three things generalise beyond this one gate:

  • Measure first, even when the plan is already written. Of four planned measures, one was dead after a single run, a second was obviously not worth its cost, and what actually worked was on none of them.
  • A flat profile points away from the code. When nothing stands out and system CPU time rises with it, the problem is the path to the data, not the work being done on it.
  • Speed must not come from silence. Every second saved has to come from something you can name: streamed instead of mounted, cached and reported.

And the honest footnote: this is a macOS problem. On Linux a bind mount reads without that penalty, and the rewrite would never have happened there. But development here runs on Macs, and a gate people bypass protects nobody, however good the technical reason for its slowness.

Patrick Lehmann

Architecture & Governance Lead

Squibble GmbH

Has spent twenty years bringing structure to IT landscapes that grew rather than were designed — as architect, developer, and operator. Writes here about the systems actually running at Squibble and the decisions behind them.

Read more

CI/CD Analytics: Where Pipeline Time Really Goes

A slow or failed pipeline is only a symptom. Workbench connects wasted runner time, job trends, and pipeline waterfalls in one investigation—from the aggregate signal to the exact merge request attempt.

Patrick Lehmann
7 min read