DEV Community

Daniel Pertu
Daniel Pertu

Posted on

Our cache TTL was shorter than the gap between reads, which makes it a timer, not a cache

Munchable's rules engine ships with a baked-in vocabulary of ingredients, and on top of that it loads a curated overlay: the words our curation pipeline has placed since the last release, plus the scoring rows that say what the engine may conclude from them. Roughly forty thousand rows, read as one snapshot under one version, by every product lookup and by every phone checking whether its copy is current.

That snapshot is cached in three tiers, cheapest first: module memory inside each serverless instance, then Redis, then the table itself. Last month I found two bugs in that arrangement. One was invisible and expensive. The other was a number I had reasoned about backwards.

The curated result is public, so you can see what is being cached: every page under munchable.app/answers is generated by running the engine over one ingredient, and the app at app.munchable.app loads the same overlay when you scan something.

The TTL was doing a job it did not have

Here is the thing I had not thought through. A write to the curated data does not refill the caches. It evicts the cached snapshot and publishes the new version, so the next reader rebuilds from the table. Eviction on write is the freshness mechanism, and on top of that, a reader that already knows a newer version than the caches hold bypasses both tiers entirely, which is what stops an instance with a stale memory copy from answering a device with an older snapshot than the version header it just saw.

Given all that, what is the Redis TTL for? Almost nothing. It is a backstop in case an eviction is lost.

It was set to five minutes, which is the number you pick when you are thinking of a TTL as the freshness mechanism. And five minutes is longer than the gap between requests on a busy service, which is the case everybody writes TTL advice for.

This is not a busy service. Real traffic is well below one taxonomy read every five minutes. So the key expired between most pairs of readers, and the next read after a quiet spell paid for a full table read and reshaping. Measured: thirty-six rebuilds a day, which is to say the cache was missing almost every time anybody asked it anything.

The fix was 5 * 60 becoming 24 * 60 * 60. Nothing else changed, because the correctness never depended on the TTL.

The general rule, which I now have written down where I will see it again: the less traffic you have, the longer your TTL should be. A TTL shorter than the interval between reads is not a cache policy, it is a timer that throws away work before anyone can use it. And if your invalidation is event driven rather than time driven, the TTL is insurance, so price it like insurance rather than like freshness.

The cap that measured the wrong string

The second bug cost much more and said nothing at all.

The snapshot is stored gzipped and base64 encoded, because Upstash's REST API carries about a megabyte per request and the JSON is bigger than that. There was a cap, 512 KB, with a branch: under the cap, write the key; over it, do not.

The cap was measured against the uncompressed JSON string. The snapshot passed it for months, until the curated overlay reached roughly twenty thousand rows. Then it stopped passing and never passed again.

What happens in the else branch matters. It did not merely skip writing the key, it deleted it, which is defensible: an over-sized snapshot means the key holds something stale. So on every read that fell through to the table, the code refilled memory, then deleted the Redis key. The Redis tier had effectively stopped existing, and every instance whose sixty second memory cache had expired paid a full table read of around thirty-two thousand rows to answer a request. About seven seconds.

Nothing errored. Nothing was logged. The product worked, and was slow in a way that looks like "the free plan database is slow".

Two changes. The cap now measures the string as stored, after gzip, and sits at 900 KB because the transport ceiling is the thing that actually constrains it:

const packed = await encodeSnapshot(snapshot);
if (packed.length <= REDIS_MAX_BYTES) {
  await redis.set(OVERLAY_KEY, packed, { ex: REDIS_TTL_S });
} else {
  // Too big to carry. Say so: this used to fail silently, and a silently
  // disabled cache costs seven seconds a read with nothing to point at.
  console.warn(
    `[taxonomy] overlay snapshot is ${packed.length} bytes compressed, over the ${REDIS_MAX_BYTES} byte cache cap; ` +
      `serving from Postgres on every memory-cache miss. Shard the key.`,
  );
  await redis.del(OVERLAY_KEY);
}
Enter fullscreen mode Exit fullscreen mode

The warning names the measured size, the cap, the consequence and the fix. Writing the remedy into the log line is the part I would defend hardest: the person reading it at 11pm is not necessarily the person who knows that sharding is the intended answer.

And the comment above the constant says what to do if it is hit again: shard the key, do not raise the cap. The cap is not a preference, it is a property of the transport. Raising it past what one request can carry converts a quiet cache miss into a request that fails.

Two small things that paid for themselves

The format version is in the key, not in the value. The key is taxonomy:overlay:v2, where v2 means gzipped and base64 encoded. v1 held plain JSON. Putting the format in the key means a deploy does not need a decoder that understands both: old values are simply never looked at, and they expire on their own. A decode failure is treated as a cache miss rather than an error, so a truncated or foreign value costs one table read and fixes itself.

Diagnostics are dropped before compressing. A fresh table read also reports which rows the engine refused to load. That list is useful to the operator, unbounded in a way the rest of the snapshot is not, and meaningless on a cache hit. So it is stripped before encoding. Caching a diagnostic is how a cached object grows without the data it represents growing.

What I would check in your cache

Three questions, in the order that found the most here:

  1. What actually invalidates this, time or an event? If it is an event, your TTL is insurance and almost certainly too short.
  2. Is the TTL shorter than the gap between two reads? If so, the hit rate is near zero no matter how correct everything else is.
  3. When a cache write is skipped, does anybody find out? A cache that silently disables itself is slower than no cache and looks like a database problem.

Related

Curation reaches the phone without an app release, and the version is just max(updated_at) is the delivery side of this snapshot, and max(x) uses the index, max(x) FILTER (where ...) scans the table is the version read that sits in front of it, which had its own 815 ms surprise in the same file.

Top comments (0)