allanninal.dev / ci

Field notes / GitHub Actions

Diagnostic GitHub Actions

a cache miss that is really a rate limit

The pipeline used to take four minutes and now takes eleven. Nothing failed. Nothing is red. The cache step reports Cache not found for input keys and the job installs everything from scratch, every time. The key has not changed and the cache still exists — the API declined to serve it, and actions/cache reports a decline the same way it reports an absence.

GitHub REST API Python and Node.js Silent slowdown
The short answer

When the cache service rate limits a repository, the action logs a cache miss rather than a rate-limit error. The job proceeds correctly and slowly, which is why it never shows up as a failure.

Two other causes look identical: a key that changes on every run because it hashes something volatile, and a fork PR, which cannot write cache entries at all by design. The API can tell them apart — the log cannot.

The problem in plain words

A cache miss is not an error. The action is built to degrade gracefully, because a missing cache should never break a build. That is correct behaviour and it is exactly what hides the problem: cost and time increase with no signal.

Because it is intermittent, it also resists reproduction. A developer re-runs the job, the cache restores, and the report gets closed as a fluke. Meanwhile every run is paying for a full install, and on a multiplied runner that is real money.

Why it happens

Graceful degradation hides the cause. The action cannot distinguish 'no entry' from 'refused to serve' in a way that is useful in a log line, so it reports the one that is safe to continue from.

Volatile keys guarantee a miss. A key built from a timestamp, a run id, or a lockfile that is regenerated during the build never matches on a later run. Every run writes a new entry and reads nothing, which also fills the repository's cache quota with garbage.

Forks cannot write caches. A fork PR can read from the base branch's cache but never writes an entry, deliberately, to stop a malicious PR poisoning the cache for everyone. So the first run on a fork PR is always cold and always will be.

How to fix it

Look at what is actually stored

The caches API lists entries with their keys and sizes. If the key you expect is absent, the problem is the key. If it is present and still missing at restore, it is the service.

gh api repos/OWNER/REPO/actions/caches \
  --jq '.actions_caches[] | {key, ref, size_in_bytes, last_accessed_at}'

Check whether the key is stable

A key must be a pure function of the inputs it protects. Hashing a lockfile is right; including github.run_id or a date is not, and produces a guaranteed miss on every run.

key: ${{ runner.os }}-node-${{ hashFiles('**/package-lock.json') }}
restore-keys: |
  ${{ runner.os }}-node-

restore-keys matters: a partial match still beats a cold start.

Watch the quota

A repository has a total cache allowance and entries are evicted least-recently-used once it is reached. Dozens of near-duplicate entries from an unstable key will evict the ones you rely on, so pruning is part of the fix.

Expect a cold cache on fork PRs

This one is not a bug and cannot be configured away. A fork PR reads the base branch's cache and writes nothing. If contributor builds must be fast, warm the cache on the base branch so there is something for them to read.

How to check it worked

Compare restore behaviour across consecutive runs on the same branch. The second should hit:

gh run view RUN_ID --log | grep -i "cache restored\|cache not found"
gh api repos/OWNER/REPO/actions/caches --jq '.total_count'

If the key list shows a new entry after every run, the key is unstable and no amount of quota will help.

The full code

The script lists the repository's cache entries, groups them by prefix, and flags the signature of an unstable key — many entries sharing a prefix, each used once. It also reports total usage against the quota, and identifies branches whose entries are being evicted.

actions_cache_audit.py
"""Diagnose why an Actions cache never restores.

A rate limit, an unstable key and a fork PR all produce the same log line: cache
miss. This separates them by looking at what is actually stored rather than at the
log, which cannot tell the difference.
"""
import argparse
import collections
import logging
import os
import re
import sys

import requests

logging.basicConfig(level=logging.INFO, format="%(asctime)s %(levelname)s %(message)s")
log = logging.getLogger("actions_cache_audit")

API = "https://api.github.com"


def prefix_of(key):
    """Everything before the final hash segment, which is what should be reused."""
    return re.sub(r"-[0-9a-f]{8,}$", "", key)


def unstable_keys(caches, min_entries=5):
    """Pure decision function.

    An unstable key writes a new entry every run and reads none, so the signature is
    many entries sharing a prefix. That fills the quota and evicts the entries you
    actually wanted, which makes it worse than a plain miss.
    """
    groups = collections.defaultdict(list)
    for c in caches:
        groups[prefix_of(c.get("key", ""))].append(c)
    return {p: entries for p, entries in groups.items() if len(entries) >= min_entries}


def main():
    ap = argparse.ArgumentParser()
    ap.add_argument("--repo", required=True)
    args = ap.parse_args()

    token = os.environ.get("GITHUB_TOKEN")
    if not token:
        log.error("set GITHUB_TOKEN")
        return 2
    headers = {"Authorization": f"Bearer {token}",
               "Accept": "application/vnd.github+json"}

    r = requests.get(f"{API}/repos/{args.repo}/actions/caches",
                     headers=headers, params={"per_page": 100}, timeout=30)
    r.raise_for_status()
    body = r.json()
    caches = body.get("actions_caches", [])

    total_gb = sum(c.get("size_in_bytes", 0) for c in caches) / 1_073_741_824
    log.info("%d cache entr(ies), %.2f GB total", len(caches), total_gb)

    suspect = unstable_keys(caches)
    for prefix, entries in sorted(suspect.items(), key=lambda x: -len(x[1])):
        size = sum(e.get("size_in_bytes", 0) for e in entries) / 1_073_741_824
        log.warning("UNSTABLE KEY  %-45s %3d entries, %.2f GB",
                    prefix[:45], len(entries), size)
    if suspect:
        log.warning("a key that changes every run writes a new entry and reads none. "
                    "Hash the lockfile, not the run id or a timestamp.")
    else:
        log.info("no unstable-key pattern; if restores still miss, check whether the "
                 "run came from a fork (forks cannot write cache entries) or whether "
                 "the cache service rate limited -- both are logged as a plain miss")
    return 0


if __name__ == "__main__":
    sys.exit(main())
actions-cache-audit.mjs
/**
 * Diagnose why an Actions cache never restores.
 *
 * A rate limit, an unstable key and a fork PR all produce the same log line: cache
 * miss. This separates them by looking at what is actually stored.
 */
const API = 'https://api.github.com';

/** Everything before the final hash segment, which is what should be reused. */
export const prefixOf = (key) => key.replace(/-[0-9a-f]{8,}$/, '');

/**
 * Pure decision function.
 *
 * An unstable key writes a new entry every run and reads none, so the signature is
 * many entries sharing a prefix. That fills the quota and evicts what you wanted.
 */
export function unstableKeys(caches, minEntries = 5) {
  const groups = {};
  for (const c of caches) {
    const p = prefixOf(c.key ?? '');
    groups[p] = [...(groups[p] ?? []), c];
  }
  return Object.fromEntries(Object.entries(groups).filter(([, v]) => v.length >= minEntries));
}

async function main() {
  const repo = process.argv[process.argv.indexOf('--repo') + 1];
  const token = process.env.GITHUB_TOKEN;
  if (!token) { console.error('set GITHUB_TOKEN'); process.exit(2); }

  const res = await fetch(`${API}/repos/${repo}/actions/caches?per_page=100`, {
    headers: { Authorization: `Bearer ${token}`, Accept: 'application/vnd.github+json' },
  });
  const { actions_caches: caches = [] } = await res.json();
  const totalGb = caches.reduce((t, c) => t + (c.size_in_bytes ?? 0), 0) / 1_073_741_824;
  console.log(`${caches.length} cache entr(ies), ${totalGb.toFixed(2)} GB total`);

  const suspect = unstableKeys(caches);
  for (const [prefix, entries] of Object.entries(suspect).sort((a, b) => b[1].length - a[1].length)) {
    const gb = entries.reduce((t, e) => t + (e.size_in_bytes ?? 0), 0) / 1_073_741_824;
    console.warn(`UNSTABLE KEY  ${prefix.slice(0, 45).padEnd(45)} ${entries.length} entries, ${gb.toFixed(2)} GB`);
  }
  if (Object.keys(suspect).length) {
    console.warn('hash the lockfile, not the run id or a timestamp');
  } else {
    console.log('no unstable-key pattern; check whether the run came from a fork, or '
      + 'whether the cache service rate limited -- both are logged as a plain miss');
  }
}

if (import.meta.url === `file://${process.argv[1]}`) main();

Add a test

The prefix logic is what separates a healthy cache from a churning one, and it has to survive keys whose hash segment is a different length or missing entirely.

test_actions_cache_audit.py
from actions_cache_audit import prefix_of, unstable_keys


def cache(key, size=1000):
    return {"key": key, "size_in_bytes": size}


def test_prefix_strips_the_hash_segment():
    assert prefix_of("Linux-node-a1b2c3d4e5f6") == "Linux-node"


def test_a_key_with_no_hash_is_unchanged():
    assert prefix_of("Linux-node") == "Linux-node"


def test_a_healthy_cache_is_not_flagged():
    caches = [cache(f"Linux-node-{h}") for h in ("a1b2c3d4", "b2c3d4e5")]
    assert unstable_keys(caches) == {}


def test_many_entries_on_one_prefix_is_flagged():
    """The signature of a key that changes every run."""
    caches = [cache(f"Linux-node-{i:08x}") for i in range(9)]
    assert "Linux-node" in unstable_keys(caches)


def test_the_threshold_is_respected():
    caches = [cache(f"Linux-node-{i:08x}") for i in range(4)]
    assert unstable_keys(caches, min_entries=5) == {}
actions-cache-audit.test.mjs
import { test } from 'node:test';
import assert from 'node:assert/strict';
import { prefixOf, unstableKeys } from './actions-cache-audit.mjs';

const cache = (key, size = 1000) => ({ key, size_in_bytes: size });

test('the prefix strips the hash segment', () => {
  assert.equal(prefixOf('Linux-node-a1b2c3d4e5f6'), 'Linux-node');
});

test('a key with no hash is unchanged', () => {
  assert.equal(prefixOf('Linux-node'), 'Linux-node');
});

test('a healthy cache is not flagged', () => {
  assert.deepEqual(unstableKeys([cache('Linux-node-a1b2c3d4'), cache('Linux-node-b2c3d4e5')]), {});
});

test('many entries on one prefix is flagged', () => {
  const caches = Array.from({ length: 9 }, (_, i) => cache(`Linux-node-${i.toString(16).padStart(8, '0')}`));
  assert.ok('Linux-node' in unstableKeys(caches));
});

FAQ

Why is a rate limit reported as a cache miss?

Because actions/cache is built to degrade gracefully — a missing cache should never break a build. It cannot express 'refused to serve' in a way that is safe to continue from, so it logs the outcome that is: a miss.

How do I tell a rate limit from a bad key?

Look at what is stored. If the key you expect is absent from the caches API, the key is the problem. If it is present and restores still miss, the service declined — and if the run came from a fork, it was never going to write one anyway.

What makes a cache key unstable?

Anything that changes between runs: a run id, a timestamp, or a lockfile regenerated during the build. The signature is many entries sharing a prefix, each used once, which also fills the quota and evicts the entries you wanted.

Why can fork pull requests not write caches?

To prevent cache poisoning. A malicious PR could otherwise write a compromised dependency into a cache that later runs on the base branch would restore. Forks read from the base branch and write nothing, by design.

Does a full cache quota cause misses?

Yes. Entries are evicted least-recently-used once the repository allowance is reached, so a churning key can evict the caches you rely on. Fixing the key usually fixes the quota as a side effect.

Related field notes

Sources

Every figure in this note is traced to one of these. Prices are list rates and change — check them for your own region before acting.

Stuck on a tricky one?

If your setup is misbehaving in a way this note does not cover, message me on LinkedIn with what you are seeing.