The cache that never hit: debugging CI when your profiler lies

It started with a complaint any frontend team will recognise:

"PR Sanity has gotten slower over the last two weeks."

Two weeks later we had three dead hypotheses, a 21x speedup that came from the one variable we had never thought to question, and the discovery that our GitHub Actions dependency cache had never produced a single hit — burning about twenty minutes of compute on every pull request, silently, for months.

This is the story of what we assumed, how each assumption died, and what the numbers actually said. The wrong turns are the interesting part, so I have kept them all in.

Part 1: Three confident hypotheses, all wrong

The symptom was real and ugly. Type-checking the main app took around 17 minutes. Run it locally without raising the heap and it did not finish at all:

FATAL ERROR: Ineffective mark-compacts near heap limit
             - JavaScript heap out of memory

With --extendedDiagnostics the picture looked damning: 97 million type instantiations, 5.4GB live on an 8GB heap, and this line:

average mu = 0.056

That is V8's mutator utilisation. It means 94% of the process's time was spent in garbage collection, not type-checking. So far, so diagnosable.

Hypothesis 1: the four hot files

We ran --generateTrace and fed it to @typescript/analyze-trace. It pointed, unambiguously, at four ag-grid column-definition files with big inline cellRenderer functions and heavy generic ColDef types.

That is a satisfying answer. It is specific, it names files, and it suggests obvious fixes.

So we tested it. We built four variants of the worst offender: one with the styled() wrapper removed, one with the JSX body of the renderer replaced by a string, one with the renderer hoisted out of the object literal, and a baseline.

Result: a 0.03% change in instantiation count.

Not 30%. Not 3%. Essentially nothing. The trace had confidently pointed at files that were not the problem. More on why below, because it happened again later.

Hypothesis 2: the duplicate csstype

Next suspect: we were loading two versions of csstype, a package that sits at the bottom of every styled-components type. Two copies means two parallel type graphs, and that genuinely can be expensive.

We confirmed the duplication, pinned a single version through resolutions, and re-measured.

Result: 0% change. Identical instantiation and type counts. Reverted.

Hypothesis 3: the heap is too small

With 94% of time in GC and 5.4GB live on an 8GB heap, "give it more memory" is the obvious move. We re-ran with 16GB.

Result: no meaningful change. It was not GC-bound in the way the mu number implied. High GC time was a symptom of the workload, not a cause we could relieve by relaxing the limit.

Hypothesis 4: maybe it isn't our code at all

Three failures in a row have a way of reframing the question. Every hypothesis so far had assumed the problem was something in our repo — our files, our dependency graph, our memory ceiling. Each one had been measured and rejected.

Which left the one variable we had been treating as fixed: the compiler itself.

So we upgraded TypeScript from 5 to 7 — the native Go port — specifically to test whether the constraint was our code or the tool type-checking it. Not a migration for its own sake; a hypothesis test, with a number attached to the outcome.

Cold lint:tsc went from roughly 17 minutes to 47.8 seconds. About 21x, at 359% CPU, because the new compiler is genuinely multi-threaded rather than pinned to one core.

That was the answer. And it retroactively explained the three failures: every measurement we had taken described the old compiler's behaviour. The 97 million instantiations, the hot files, the 94% GC ratio — all real, all accurate, and all properties of an implementation we were about to replace. We had been optimising our code to suit a bottleneck that lived in the tool.

Lesson 1. When you profile, you measure your code and the tool measuring it. If several code-level hypotheses die in a row, promote the tool from constant to variable and test it directly. Upgrading the compiler took an afternoon; the three experiments that preceded it took days.

Part 2: We were measuring the wrong job entirely

Here is the thing that should have come first. When we finally plotted CI wall time against lint:tsc duration, the median lint:tsc time had been flat the whole time.

CI had absolutely gotten slower. lint:tsc just was not why. It was the loudest job, not the slowest one.

The real critical path was the main application's test suite, running as a single job for 26 minutes. We split it across parallel shards, which brought it to 9 minutes per shard. Because the shards run concurrently, wall time is the slowest one — so the critical path shrank by roughly 3x, and the job nobody had complained about stopped being the thing everyone waited on.

Lesson 2. "Job X feels slow" is a hypothesis, not a measurement. Measure the critical path before optimising anything on it — the loudest job and the slowest job are rarely the same one.

The second lying profiler

With tests sharded, ESLint became the bottleneck at around 11 minutes. We ran it with TIMING=all, which attributes time per rule. One rule stood out enormously: react-hooks/static-components, credited with 89.5 seconds.

An easy win — just disable it.

Except when we disabled it, wall time did not improve. Not by 89 seconds; not at all. We then disabled all six React Compiler rules together. Still nothing.

The explanation is that these rules are type-aware. The expensive work is building the shared TypeScript program, and the profiler attributes that shared cost to whichever rule happens to touch it first. static-components was not slow. It was first.

Turning it off would have cost us real lint coverage in exchange for zero seconds.

Lesson 3. A profiler tells you where time was attributed, not where it was spent. Both times we trusted attribution without a controlled experiment, we were wrong. The experiment is cheap: remove the suspect, re-measure, and see if the total actually moves.

The win that was real

ESLint 9.39 has a --concurrency flag. Turning it on gave a genuine 2.35x locally (451.8s → 191.9s), with byte-identical findings.

We shipped --concurrency 4 rather than auto. On a 16-core machine auto was no faster in our later head-to-head (159.4s vs 160.0s) but used nearly twice the peak memory — 26.79GB against 14.89GB — because every worker builds its own TypeScript program. On a CI box, that is the difference between working and being OOM-killed.

In CI the lint step went from 683s to 239s, a 2.9x improvement.

Part 3: The cache that had never worked

Now the good part.

While reading step timings, something looked wrong. One lint leg was doing 2 seconds of real work — Turborepo's remote cache was replaying everything correctly — but the job still took over two minutes. A small package's test leg was the same: 1 second of work, 98 seconds of yarn install.

Every leg in the matrix was installing dependencies from scratch. On every PR.

The cause was four lines of YAML in two different files that nobody had ever read side by side.

The PR workflow restored with a lockfile-hashed key:

# PR workflow
key: ${{ runner.os }}-yarn-${{ hashFiles('**/yarn.lock') }}
restore-keys: |
  ${{ runner.os }}-yarn-main-

The main-branch workflow saved under a literal one:

# main-branch workflow
key: ${{ runner.os }}-yarn-main-

Linux-yarn-main- can never equal Linux-yarn-<hash>. The primary key could not match, by construction. Every leg fell through to the restore-keys prefix.

And here is the detail that turns a slow cache into a useless one: a restore-keys match is a partial restore, and it does not set cache-hit. The install step was gated on exactly that:

- name: Install dependencies
  if: steps.cache.outputs.cache-hit != 'true'

So the install always ran. Every leg. Every PR. Confirmed in the logs — every leg reported Cache restored from key: Linux-yarn-main-.

GitHub also scopes caches per branch, so the cache a PR saves for itself is invisible to every other PR. That fallback was the only thing any PR ever got.

Bug two: the cache was frozen

actions/cache/save will not overwrite an existing key. Because main saved under a fixed literal key, every save after the very first one silently failed. That cache was frozen at whatever it contained the first time it was ever written, and would never reflect a dependency change until GitHub evicted it.

Bug three: the key was not even deterministic

hashFiles('**/yarn.lock') is unanchored. Our repo has several yarn.lock files, and some of them live inside node_modules — vendored by transitive dependencies, and restored by the cache step itself.

So the key depended on whether node_modules already existed. Simulating GitHub's hashFiles (sha256 over the concatenated sha256 of each matched file) against the real files:

**/yarn.lock, node_modules absent : 2bcefcb4355fe915f7e5063ed2355bf8af3e8ce0a...
**/yarn.lock, node_modules present: 13d39ebbdd8270f6662962410123af95fb3716a2...
yarn.lock       (either case)     : 2bcefcb4355fe915f7e5063ed2355bf8af3e8ce0a...

Two different keys for identical dependencies. That is not academic when your jobs run on self-hosted runners where a workspace can be reused.

Bug four: a cache nobody read

While fixing the above we grepped every workflow for a Turbo cache restore step. There wasn't one. Main had been dutifully saving ~/.turbo on every push, under a key no workflow anywhere restored — and Turbo remote caching was already enabled, so it was redundant twice over.

The fix was small: hash the key on main, anchor hashFiles to the root lockfile, widen the fallback prefix, delete the dead step. An exact hit also eliminates the post-step churn for free, because actions/cache skips saving when the primary key hit — those 34–51 second post steps drop to zero.

Part 4: every fix creates a new failure mode

Two review comments on that PR were sharper than anything in the fix itself, and both described bugs the fix had introduced.

The poisoned cache. Making the keys match removed a safety net nobody knew was load-bearing. Previously, the always-partial restore meant yarn install always re-ran and repaired anything incomplete. Now that PRs hit exactly and skip install, a save step gated on if: always() could publish a half-finished node_modules from a failed install — under a key actions/cache/save then refuses to overwrite. It would stick until someone manually evicted it, and it would be inherited by every workflow in the repo that skips install on a cache hit.

The fix gates the save on the install step succeeding, not on the job succeeding, so a failed build still saves a perfectly valid dependency tree:

- name: Yarn install
  id: yarn_install
  run: yarn install --frozen-lockfile

- name: Save Yarn cache
  if: always() && steps.yarn_install.outcome == 'success'

The informational step that could block every PR. We added a step to report per-leg timings into the job summary. Harmless, except it lived in the single required status check, and the default shell for run steps is bash --noprofile --norc -eo pipefail. Any rate limit or transient 5xx from gh api would fail the step, fail the gate, and block a completely green PR.

Worse: we had put it first, and the actual evaluation step had no if: — so a reporting hiccup would have skipped the verdict entirely and reported failure for a reason indistinguishable from a real test failure.

It now runs after the gate has decided, with continue-on-error: true.

Lesson 4. When you remove a workaround, find out what it was quietly protecting you from. And never let a reporting step share a job with a required gate.

Part 5: a guard that measures the right thing

Finally, we wanted CI to fail if it got slow again. The obvious version — "fail if the run takes over 15 minutes" — would have been a disaster.

Measured across the last 22 successful runs, wall time was median 10.9 min, p90 15.2 min, max 21.2 min. A 15-minute wall-time gate would have failed roughly one PR in six — and much of that tail is time spent queued waiting for a self-hosted runner, which no PR author can influence. Failing someone's PR because the runner pool was busy is exactly the kind of flaky gate that teaches a team to ignore CI.

GitHub's native timeout-minutes counts from when the job starts executing and excludes queue time. Measuring that instead, across 77 individual jobs: the slowest single execution was 10.9 minutes, and zero jobs exceeded 15.

Same number, completely different meaning. One breaks a sixth of your PRs; the other has 37% headroom and blocks nothing.

timeout-minutes: 15

One line, native, no script. A cancelled leg already makes the aggregate check fail, so nothing else needed wiring.

What we would tell ourselves two weeks ago

1. Measure the critical path first. The loudest job is rarely the slowest one. Our headline complaint was about a job whose median duration had never changed.
2. Profilers report attribution, not causation. Twice we were pointed at a confident, specific, wrong answer. The controlled experiment — remove it, re-measure — takes minutes and settles it.
3. A hypothesis you did not try to disprove is just a preference. Three of ours died on contact with a measurement. That is the process working, not the process failing.
4. Read your CI config across files, not within them. Both halves of our cache were individually reasonable. The bug only existed between two files that no single person had read together.
5. Your toolchain is a variable, not a constant. We spent days tuning code to fit the compiler before testing the compiler itself. Upgrading it beat every code change we tried, by a factor of twenty.
6. Every fix is a change, and changes have failure modes. The best review comments we got were about bugs our own fix had just introduced.

The most uncomfortable lesson is the first one. The cache bug had been there for months, costing twenty minutes of compute per PR, in plain sight. We only found it because we finally stopped optimising the thing everyone complained about and started reading the step timings of the jobs nobody mentioned.