Databases Bug Report

Cache stampede when a hot Redis key expired and pushed Postgres to 100% CPU

Every ten minutes our catalog API spiked to 4-second responses and the database hit 100% CPU. A hot Redis key expired and 600 requests rebuilt it at once. Single-flight, a short Redis lock, stale-while-revalidate and TTL jitter fixed it.

Daniel Tran Daniel Tran @fun_dev · March 20, 2025 · 8 min read · 7 Views
Banner: cache stampede when a hot Redis key expired and pushed Postgres to 100% CPU

Our marketplace catalog API serves the home page "trending categories" block, which needs a fairly expensive aggregate query across listings, sales and reviews. We cache the result in Redis for ten minutes. In March the Grafana board started showing a sawtooth: every ten minutes, p99 latency for the home page jumped from 60 ms to around 4 seconds for 15 to 20 seconds, and Postgres CPU hit 100%.

The API logs during the spikes were full of timeouts waiting for a database connection (our own log lines, with fields copied from pgxpool.Stat()):

level=error msg="trending: load failed" err="context deadline exceeded" waited_for_conn=2.91s
level=warn msg="db pool saturated" acquired=40 max=40 empty_acquire_count=18734

And pg_stat_activity at the peak showed the same query 40 times, one per pool connection, all running concurrently.

Reproducing it

On staging, with a load test at production rate (about 600 requests per second on the home page):

redis-cli -h redis.staging.example.com DEL catalog:trending:v3

Deleting the key reproduced the spike instantly: every in-flight request found the cache empty and started its own rebuild.

What we ruled out

  • Redis itself. Redis latency stayed under 1 ms through the spikes and INFO stats showed no evictions; the key expired by TTL, exactly as configured.
  • A slow query plan change. The aggregate ran in 350 ms alone. It only became slow when 40 copies competed for CPU and I/O.
  • A cron job. The spikes were not on wall-clock boundaries; they drifted with the time the key was first written after each deploy.

Root cause

The read path was the classic cache-aside pattern with no coordination:

func (s *Service) Trending(ctx context.Context) ([]Category, error) {
    if b, err := s.rdb.Get(ctx, trendingKey).Bytes(); err == nil {
        return decode(b)
    }
    cats, err := s.repo.LoadTrending(ctx) // 350 ms alone, seconds under contention
    if err != nil {
        return nil, err
    }
    s.rdb.Set(ctx, trendingKey, encode(cats), 10*time.Minute)
    return cats, nil
}

When the key expired, every request that arrived during the rebuild (350 ms at best, several seconds under contention) missed and ran the query too. With 12 API pods and 600 requests per second, that was hundreds of concurrent rebuilds for a value that only needed computing once.

What is happening under the hood

A cache stampede (also called dogpile or thundering herd) happens when a popular cache entry becomes unavailable and many clients try to regenerate it at the same time. The more expensive the regeneration, the longer the window, and the more requests pile into it, which makes the regeneration even slower. It is a positive feedback loop that can take down the database the cache was meant to protect.

Three properties made ours severe: one key served most traffic, the TTL was fixed so it expired at a single instant, and nothing prevented duplicate work, either inside one process or across pods.

Environment

Component Version / value
OS Debian 12 containers on Kubernetes 1.31
Runtime Go 1.24.1
Redis client go-redis v9.7
Cache Redis 7.4, single primary with replica
Database PostgreSQL 16.6, 8 vCPU
API 12 pods, pgxpool max 40 connections per pod

Minimal reproduction

Any cache-aside read with a fixed TTL and concurrent readers shows it. Count how many times the loader runs when 500 goroutines hit an empty cache:

var loads atomic.Int64
load := func() string { loads.Add(1); time.Sleep(300 * time.Millisecond); return "v" }

var wg sync.WaitGroup
for i := 0; i < 500; i++ {
    wg.Add(1)
    go func() { defer wg.Done(); if cache.Get("k") == "" { cache.Set("k", load()) } }()
}
wg.Wait()
fmt.Println("loads:", loads.Load()) // close to 500, not 1

Who is affected

Any service with a small number of hot keys, an expensive miss path and high concurrency. Low-traffic keys rarely stampede; it takes enough requests to arrive during one rebuild window.

We layered four changes. Each one helped on its own; together they removed the spike.

The fix

1. Collapse duplicate loads inside a process with singleflight. Concurrent callers for the same key share one in-flight call:

import "golang.org/x/sync/singleflight"

var group singleflight.Group

func (s *Service) loadOnce(ctx context.Context) ([]Category, error) {
    v, err, _ := group.Do(trendingKey, func() (any, error) {
        return s.rebuild(context.WithoutCancel(ctx))
    })
    if err != nil {
        return nil, err
    }
    return v.([]Category), nil
}

We pass a context without cancellation so one impatient caller cannot cancel the shared rebuild for everyone else; rebuild applies its own 5-second timeout.

2. Collapse across pods with a short Redis lock. Only the pod that wins SET NX rebuilds; others serve stale data (step 3) or wait briefly:

func (s *Service) rebuild(ctx context.Context) ([]Category, error) {
    ctx, cancel := context.WithTimeout(ctx, 5*time.Second)
    defer cancel()

    token := uuid.NewString()
    ok, err := s.rdb.SetNX(ctx, trendingKey+":lock", token, 10*time.Second).Result()
    if err != nil || !ok {
        return s.waitForFresh(ctx)
    }
    defer releaseLock.Run(ctx, s.rdb, []string{trendingKey + ":lock"}, token)

    cats, err := s.repo.LoadTrending(ctx)
    if err != nil {
        return nil, err
    }
    s.store(ctx, cats)
    return cats, nil
}

// Delete the lock only if we still own it.
var releaseLock = redis.NewScript(`
if redis.call("GET", KEYS[1]) == ARGV[1] then return redis.call("DEL", KEYS[1]) end
return 0`)

3. Serve stale while revalidating. We now store the value with a logical "fresh until" time and a longer physical TTL. Readers return the cached value immediately; if it is past its fresh time, one background refresh starts:

type entry struct {
    Data       []Category `json:"data"`
    FreshUntil time.Time  `json:"fresh_until"`
}

func (s *Service) Trending(ctx context.Context) ([]Category, error) {
    e, err := s.read(ctx)
    if err != nil { // true miss: cold start or Redis flush
        return s.loadOnce(ctx)
    }
    if time.Now().After(e.FreshUntil) {
        go s.loadOnce(context.WithoutCancel(ctx)) // singleflight + lock dedupe this
    }
    return e.Data, nil
}

4. Add TTL jitter. Fresh time is 10 minutes plus or minus 10%, and the physical TTL is one hour, so related keys do not expire together:

func (s *Service) store(ctx context.Context, cats []Category) {
    fresh := 9*time.Minute + time.Duration(rand.Int64N(int64(2*time.Minute)))
    b, _ := json.Marshal(entry{Data: cats, FreshUntil: time.Now().Add(fresh)})
    s.rdb.Set(ctx, trendingKey, b, time.Hour)
}

Alternatives and trade-offs

  • Probabilistic early expiration (each reader refreshes early with a probability that rises as expiry approaches). Elegant and lock-free, but harder to reason about in incident reviews. Our stale-while-revalidate plus lock gives similar results with explicit behaviour.
  • Refresh from a scheduler so readers never rebuild. Ideal for a handful of known keys; we did this for the home page block later. It does not help long-tail keys.
  • Longer TTL only. Spikes become rarer, not smaller, and data goes stale.

How to test the fix

A unit test with a fake repository counts loader calls under concurrency:

func TestTrendingSingleLoadUnderConcurrency(t *testing.T) {
    repo := &countingRepo{delay: 200 * time.Millisecond}
    svc := newTestService(t, repo) // miniredis-backed

    var wg sync.WaitGroup
    for i := 0; i < 300; i++ {
        wg.Add(1)
        go func() { defer wg.Done(); _, _ = svc.Trending(context.Background()) }()
    }
    wg.Wait()

    if got := repo.calls.Load(); got != 1 {
        t.Fatalf("expected 1 load, got %d", got)
    }
}
go test ./internal/catalog/... -run TestTrending -race -count=20

On staging we repeated the DEL under 600 requests per second: one rebuild query appeared in pg_stat_activity and p99 stayed under 120 ms.

Confirming in production

  • The ten-minute sawtooth disappeared. Home page p99 has stayed between 55 and 80 ms for a month.
  • Postgres CPU during refresh moments went from 100% to a 6 to 8 point blip.
  • We count rebuilds with a metric; it reads one rebuild per key per refresh period across all pods.
curl -s http://catalog-api:9090/metrics | grep catalog_cache_rebuilds_total
  • Lock contention metric (lock_not_acquired_total) shows the other pods backing off as designed.

Regression guard

  • The concurrency test above runs in CI with -race.
  • Our cache helper is now the only sanctioned way to cache expensive reads; a lint check flags direct rdb.Set calls with a time.Minute literal TTL outside the helper package.
  • An alert fires if more than three identical normalised queries run concurrently in Postgres for over 10 seconds.

Security implications

Before the fix, anyone who could force cache misses (for example by a Redis flush during an incident or by hitting uncached variants) could degrade the database for everyone, an availability risk. The lock key uses a random token and a compare-and-delete script so one pod cannot release another's lock. Serving stale data means a short window where data is older than ten minutes, which product accepted for trending lists; we do not use stale-while-revalidate for prices or stock.

Prevention checklist

  • Identify hot keys and their miss cost before choosing a TTL.
  • Deduplicate rebuilds in-process and across instances.
  • Prefer serving slightly stale data to blocking on a rebuild, where the product allows it.
  • Add jitter to TTLs so keys do not expire in lockstep.
  • Load test cache expiry, not just warm caches.

References

Add a label

#postgresql #redis #golang #cache-stampede #singleflight
Written by
Daniel Tran @fun_dev

I have spent most of my career on the side of software that pages people at night: payment integrations, web platforms with real traffic, CI/CD pipelines, Kubernetes clusters and the databases underneath them. Somewhere along the way I started keeping a notebook of every bug that cost more than an hour — the exact error, what we ruled out, the real root cause and how we proved the fix. Hibug is where those notes live. Every post follows the same path: Investigate, Explain, Fix, Verify — with the environment spelled out, the fix tested, and the security angle checked.

Advertisement

Comments

0

No comments yet. Be the first to comment!

Sign In to post a comment.