Redis in front of a report that was still slow

1,963 words, about 9 min read

The settlement report took 9.4 seconds at the median. I put Redis in front of it in August, watched the median fall to 81 milliseconds, and made the report worse for the people who had complained about it. The p99 went from 11.2 seconds to 14.8. It took me a week to understand why, and the answer was not in any Redis documentation, because it was not Redis doing anything wrong.

The report itself is an aggregate: about 4.1 million shipment rows joined to payments, grouped by courier and by week, with fourteen filters in the UI. It runs against a MySQL 5.7 read replica. Finance opens it perhaps forty times a day and the operations shift opens it all at once at 09:00, which turns out to matter a great deal.

Why the cache had to live in the application

The first thing three people asked was why we did not just let MySQL cache it. Because that option is going away. The query cache was deprecated in MySQL 5.7.20, and the 8.0.3 release notes record the removal: FLUSH QUERY CACHE, RESET QUERY CACHE, the SQL_CACHE modifier and the related thread states are all gone, while SQL_NO_CACHE stays in the grammar with no effect. We are on 5.7 and will be on 8.0 within a year or two. Building on a feature with a published removal date is a choice you make once and regret twice.

It also would not have helped. The MySQL team’s own post on retiring the query cache lists the restrictions plainly: the query must match byte for byte, and any modification to the underlying tables invalidates the whole cache for those tables. Every date range produces different statement text, so September and October share nothing. And the booking table takes writes continuously. A cache that empties itself whenever a courier scans a parcel is not a cache. The same post makes the argument I ended up making internally, that caching helps most when it is moved closer to the client, and notes the cache has been off by default since 5.6 in 2013, which is why nobody on the team had ever seen it do anything for us anyway.

So the cache had to be ours: a Redis instance running 5.0.6, which came out on 25 September and went on the box the week after, and phpredis 5.0.2 in a Symfony 4.3 app on PHP 7.3.

The first version, and the p99 it created

Version one was six lines. Build a key, GET it, and on a miss run the query and store the JSON with SETEX, which is just SET with EX in one command, at a 300 second TTL. Median 81 milliseconds. The graph looked like the kind of thing you screenshot.

The p99 got worse because of what happens at the exact moment a key expires. Nine requests are in flight at 09:00. The key has just gone. All nine miss, all nine start the same nine second aggregate against the same replica, and now they are competing for the same buffer pool and the same temporary table space, so the query that takes 9.4 seconds alone takes 14 seconds when there are nine of it. Then all nine write the same value to the same Redis key, eight of those writes being pure waste.

A TTL is a cliff, not a slope. Every expiry is a small coordinated outage, and it lands precisely when the report is most popular, because popularity is what put the key there in the first place. We had turned one slow report into a slow report that also has a synchronised thundering herd every five minutes.

Two users, one report

Before I fixed that, a worse bug surfaced. The key in version one was the string report:settlement. No filters in it. Two people running different date ranges were reading each other’s numbers, and it took three days to be reported because the totals looked plausible. Someone in finance reconciled part of a month against a September figure that was actually August.

Key construction is now deliberate and it is the part of this I would keep unchanged:

<?php
// src/Report/SettlementReportCache.php

private const PREFIX = 'rpt:v3:settlement';

private function cacheKey(ReportFilters $filters): string
{
    $parts = [
        'account'  => $filters->accountId(),
        'from'     => $filters->from()->format('Y-m-d'),
        'to'       => $filters->to()->format('Y-m-d'),
        'couriers' => $filters->courierIds(),
        'statuses' => $filters->statuses(),
        'group'    => $filters->groupBy(),
        'currency' => $filters->currency(),
    ];

    // two users who picked the same couriers in a different order
    // must land on the same key
    sort($parts['couriers']);
    sort($parts['statuses']);

    $digest = hash('sha256', json_encode($parts, JSON_THROW_ON_ERROR));

    return self::PREFIX . ':' . substr($digest, 0, 24);
}

Four rules came out of that afternoon. The account identifier goes in the key, always, because a cache key that omits the tenant is an authorisation bug with a TTL. Filter values are normalised before hashing, so equivalent filter sets collide on purpose rather than by luck. The prefix carries a version, v3, so when the row shape changes we bump it and the old keys age out on their own instead of needing a flush. And no raw user input goes into a key, because user input has no length limit and Redis keys should be predictable when you are staring at SCAN output at eleven at night.

A lock and a stale copy

The stampede fix has two parts and neither is clever. Split the entry into a payload key with a long TTL and a freshness marker with a short one, then let exactly one process do the refresh while everyone else reads the slightly old payload. SET has taken NX and EX together since 2.6.12, which is all the lock needs to be. Two phpredis details in the code below, both from its README: options go in as an array, ['nx', 'ex' => 45], and exists() has returned a count rather than a boolean since 4.0.0, which is why it is compared against zero.

<?php
public function get(ReportFilters $filters): array
{
    $key = $this->cacheKey($filters);

    $payload = $this->redis->get($key);                   // TTL 3600
    $isFresh = $this->redis->exists($key . ':fresh') > 0; // TTL 300

    if ($payload !== false && $isFresh) {
        return json_decode($payload, true, 512, JSON_THROW_ON_ERROR);
    }

    $token = bin2hex(random_bytes(8));
    $hasLock = $this->redis->set($key . ':lock', $token, ['nx', 'ex' => 45]);

    if (!$hasLock) {
        if ($payload !== false) {
            // stale is the right answer here, and it is 80ms old at worst
            return json_decode($payload, true, 512, JSON_THROW_ON_ERROR);
        }

        usleep(300000); // cold key only: wait for the holder, then look again
        return $this->get($filters);
    }

    try {
        $rows = $this->query->run($filters); // the 9.4 second one
        $encoded = json_encode($rows, JSON_THROW_ON_ERROR);

        $this->redis->setEx($key, 3600, $encoded);
        $this->redis->setEx($key . ':fresh', 300, '1');

        return $rows;
    } finally {
        $this->releaseLock($key . ':lock', $token);
    }
}

private function releaseLock(string $key, string $token): void
{
    // never delete a lock someone else now holds
    $this->redis->eval(
        'if redis.call("get", KEYS[1]) == ARGV[1] '
        . 'then return redis.call("del", KEYS[1]) else return 0 end',
        [$key, $token],
        1
    );
}

The token and the Lua release are not decoration. Without them, a worker whose query overran its lock TTL comes back and deletes the lock a different worker is currently holding, and you are back to two processes running the same aggregate. With them, the overrunning worker deletes nothing and logs a warning, which is how we learned our worst case is 21 seconds rather than 9.4 when the replica is lagging. The lock TTL is 45 seconds for that reason and I am not comfortable with it: it is a guess with a safety factor, and if a query ever takes longer we get a duplicate refresh instead of a corrupted result, which is the failure I chose.

The Lock component has existed since Symfony 3.4 and has a Redis store, and for a job mutex that is what I would reach for. Here it only solves half the problem. The lock is the easy half; the stale-while-revalidate behaviour, two keys and the decision to serve old numbers rather than make someone wait, is the half that moved the p99, and no library was going to make that call for me.

Memory, eviction, and one OOM reply

We ran for six weeks with no memory limit, which on a 64-bit build means the dataset can grow until the kernel takes an interest. Then I set maxmemory 512mb and left the rest alone, and the rest matters: the shipped redis.conf defaults maxmemory-policy to noeviction. On a Friday afternoon somebody exported about sixty filter variants in a row, we crossed the limit, and every write started coming back as

OOM command not allowed when used memory > 'maxmemory'.

Reads kept working, which made it confusing for ten minutes. We moved to allkeys-lru. Every key we write has a TTL, so volatile-lru would also have been correct, but the eviction documentation makes the case for allkeys-lru as the sensible default when a subset of keys is much hotter than the rest, and it does not depend on every future developer remembering to set an expiry. The same page notes that storing an expire costs memory, which is a small argument in the same direction.

Report payloads range from 40 KB to about 900 KB of JSON, so 512 MB holds a few thousand of them, and the LRU approximation samples rather than computing exact recency. Fine for this. We store JSON rather than a serialised PHP structure purely so that the value is readable in redis-cli when a number looks wrong. For hit rate we read keyspace_hits and keyspace_misses from INFO stats, and we also keep our own per report counters with INCR, calling EXPIRE on the counter only when INCR returns 1, since that is the call that created it.

Where it sits now

The queries per hour number is the one I did not expect. The naive cache increased database load, because the stampede duplicated work that the uncached version had at least been doing once per request. The lock cut it to six per hour, which is roughly one refresh per distinct filter set per five minutes, which is what the design says it should be.

The remaining 1.1 seconds at p99 is not the stampede. It is cold keys. About 31 percent of report loads still miss entirely, because the filter space is large enough that plenty of people construct a combination nobody has asked for before, and a cache does nothing for a query that is slow the first time. The honest fix is a summary table maintained by a nightly job, so that the aggregate is a read of 8,000 pre-grouped rows instead of 4.1 million raw ones. I have sketched it twice. It is more work than everything described above, and it is the next thing.

Sources

• MySQL 5.7.20 release notes, for the query cache deprecation and the statement it covers.
• MySQL 8.0.3 release notes, for the removal of the query cache, SQL_CACHE and the query cache thread states.
• Redis SET documentation, for NX and EX being available together since 2.6.12 and for SETEX being equivalent to SET key value EX seconds.
• Redis key eviction documentation, for maxmemory, the policy list, the case for allkeys-lru, the memory cost of expires, and keyspace_hits.
• redis.conf on the 5.0 branch, for the default maxmemory-policy noeviction and the behaviour when the limit is reached.
• Redis 5.0 release notes, for the 5.0.6 release date of 25 September 2019.
• MySQL 8.0: Retiring Support for the Query Cache, for byte-for-byte statement matching, table-level invalidation, and the cache being off by default since 5.6.
• Symfony Lock component changelog, for the component landing in 3.4.