A cold cache is not free

The production numbers came back as three runs of the feature-flags list view: 22,812, 22,278 and 22,456 milliseconds, each with 85 queries. Flipping a single flag took between 15.7 and 16.7 seconds. I had already written a fix for this page by then, and on my machine it measured 31 milliseconds. Both numbers were real, taken at different moments in the life of a process.

The page is an admin view over the app's feature flags, 84 of them. To build it, the server scans the codebase and the docs for flags and reads each flag's state from the database. The page and the flip had both been slow, slow enough that I went looking.

The page was paying for three things on every request. It re-ran a code scan that walked the source tree and parsed about 4,000 Python files, plus a scan of the docs. It queried the database once per flag to resolve its state. And a flip re-ran both scans, after which the page threw away its data and fetched the whole board again, paying for the full computation a second time.

Locally, against the production database in read-only mode, the computation took 7,263 milliseconds and 85 queries for 84 flags. Enumerating the flags alone was 4,378 of those milliseconds. The query count grew with the number of flags, which is the shape I like least, because it gets worse by itself as the app grows.

The first change went after all three. Scan results are cached, keyed on the git commit the process booted with plus the scan roots, and nothing is cached when that commit is unknown. All flag rows load in one query. A flip now returns only the row that changed, and the front end patches that row into its cache instead of refetching the board, with a refetch as the fallback if the response has no row. Cached results are deep-copied on every call, so one caller cannot corrupt what the next one sees.

Warm, the page dropped to 31 milliseconds with one query, and a flip to 26 milliseconds with one query. A guard test pins the query count so it cannot grow with the flag count. Reverting to per-flag lookups fails it with 4 queries for 3 flags but 41 for 40.

In that same change, under the things I had not checked, I wrote down the hole in plain words:

First request per gunicorn worker after a deploy still pays the cold scan. No boot-time pre-warm was added.

Locally that first call took 4.4 seconds. I listed it as a known gap and moved on.

The production baseline is what made the gap expensive. I ran it on the production host, in-process, with query counts:

production, cold worker      time (ms)                    queries
list view                    22,812 / 22,278 / 22,456     85
flip view                    16,666 / 16,201 / 15,674     5
enumerate_flags()            about 13,900
scan_documented_flags()      about 530

Enumerating the flags alone took about 13,900 milliseconds, more than three times the local figure, and the docs scan about 530. The app deploys itself several times a day. Each deploy starts fresh web workers, and each worker begins with an empty cache, because the cache lives in that process's memory. So the first request to each worker after each deploy paid about 15 seconds, and since I am the one who uses that page, I was often the one who landed on a cold worker.

Every check I had run was against a warm process. The cached page answered in 31 milliseconds because some earlier request had already paid the full price. Clicking the page a second time to see whether it was fast told me nothing about the first click.

The second change warms the scan when each web worker boots. A background thread starts from the app's startup hook, records the boot commit if nothing has yet, and builds both scans. It reads files only and never touches the database. If it fails, it logs a warning and never raises, and requests fall back to the lazy scan they used before.

It only starts under the real web server. The thread checks whether the process was launched by gunicorn, so management commands, Celery workers, tests and the dev server never start it. They do not need a warm flag cache, and they should not spend fourteen seconds of CPU at startup on one.

The cost does not go away. Each web worker still spends about 14 seconds of CPU on the scan, the same work it used to do on the first request. The warm-up moves that cost onto boot, where nobody is waiting on it, and the total stays the same.

Two things are still open. The gunicorn check depends on the process name matching the path in the service definition, and I did not run it under real gunicorn locally. The target I set in advance was a console page load under one second right after a deploy, and that after-deploy timing has not been recorded yet. Until it is, the warm-up is a change I expect to work and have not yet watched work. The part I would redo is the note in the first change. I wrote down that the first request still paid and treated it as a footnote, when that first request was the one I kept hitting.