Skip to content

Redis KEYS in a hot loop blocks the whole instance for every service #7833

Description

@gsalingu

What happens

RedisStore.Keys() in engine/cache/redis.go issues the Redis KEYS command.

KEYS is O(N) over the entire keyspace, and Redis executes commands on a single
thread — io-threads parallelises socket reads and protocol parsing only, not
command execution. So for as long as a KEYS call runs, every other client of
that Redis waits, whatever it was asking for.

The CDN calls this in a hot loop. engine/cdn/cdn_log_engine.go:

func (s *Service) waitingJobs(ctx context.Context) {
	for {
		time.Sleep(250 * time.Millisecond)
		...
		keyListQueue := cache.Key(keyJobLogQueue, "*")
		listKeys, err := s.Cache.Keys(keyListQueue)

Four full keyspace scans per second, forever, for the lifetime of the service.

Measurements

From a CDS instance with a 143k-key Redis (redis_version 7.4.3, io-threads 1):

SLOWLOG LEN                     128
entries matching KEYS cdn:log:job:*   128   ← every single entry
per-call duration                27,085–35,560 µs  (27–35 ms)
DBSIZE                           143,523
instantaneous_ops_per_sec        252
redis CPU under load             88% of a core

Every entry in the slow-command log was this one call. Nothing else in the
system was slow enough to register.

The knock-on effect is not confined to the CDN — every CDS service shares this
Redis, so the stall lands on lock acquisition, queue pops and cache reads
belonging to unrelated components. On our instance a repository analysis sat
unclaimed for 136 seconds while its poller ticked every 5 seconds, because
each tick's Redis work was queued behind these scans.

Severity depends on keyspace size

The blocking is inherent to KEYS on any Redis deployment, but the cost is
O(keyspace). A small installation may never notice; ours became unusable. Worth
saying plainly so the report isn't read as universal breakage.

Proposed fix

Walk the keyspace with SCAN instead. Same result, never blocks for more than
one batch. SCAN can return duplicates across cursor steps (de-duplicated) and
is a moving view rather than a snapshot — for a caller polling to find work to
pick up, that is what KEYS gave it in practice anyway.

PR: #7837

After the change, same instance

SLOWLOG LEN                     0        (was 128, all KEYS)
command latency                 0.00 ms  (was 27–35 ms blocking)
instantaneous_ops_per_sec       153      (was 252)
redis CPU                       47.6%    (was 88%)
CDN "unable to list jobs queues" errors   0

Batch size matters: at COUNT 1000 the 143k keyspace takes ~140 cursor steps
and the command rate went up (252 → 523/s) before settling at ~15 steps and
153/s with COUNT 10000.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions