Instrumenting Redis Clients and Cache Operations

Record cache.hit as a boolean on each cache span and template the key rather than recording it, then decide deliberately whether every command gets a span — because a service issuing forty cache calls per request produces more spans from Redis than from everything else combined.

Context and when it matters

Cache instrumentation answers a different question from database instrumentation. A Redis GET takes a few hundred microseconds; its duration is almost never the problem. What matters is whether it hit, because a cache that is fast and always missing is strictly worse than no cache — you pay the round trip and then do the expensive work anyway.

The second reason to care is volume. Cache clients are the most common cause of span-volume blowouts, and the resulting pressure lands on the batch processor and the storage bill rather than on the application. Deciding how much cache detail you actually need is part of instrumenting it.

Hit ratio from spans

What a cache hit and a cache miss look like in a trace Two waterfalls. In the hit path, a GET product span of one millisecond sits under a six millisecond handler. In the miss path, the GET returns nothing in one millisecond, then a database SELECT takes eighty milliseconds and a SETEX takes one millisecond, under a ninety-four millisecond handler. The miss is where the latency lives — label it, or you cannot count it cache.hit = true handler 6 ms GET product · 1 ms · hit cache.hit = false handler 94 ms GET · 1 ms · miss SELECT product · 80 ms SETEX Group by cache.hit and the p95 of the two populations differs by an order of magnitude — that gap is the value of the cache. 
from opentelemetry import trace

tracer = trace.get_tracer("app.cache")

def get_product(product_id: str):
    with tracer.start_as_current_span("GET product") as span:
        span.set_attribute("db.system.name", "redis")
        span.set_attribute("db.operation.name", "GET")
        # Key TEMPLATE — bounded. The literal key is one value per product and
        # has no business being an aggregation dimension.
        span.set_attribute("cache.key.template", "product:{id}")
        raw = redis.get(f"product:{product_id}")
        hit = raw is not None
        # Exactly two values: safe to promote into span metrics for a dashboard.
        span.set_attribute("cache.hit", hit)
        if hit:
            return deserialize(raw)
        # The miss path stays inside the same trace, so the waterfall shows
        # miss → database read → cache write as one causal chain.
        product = load_from_db(product_id)
        redis.setex(f"product:{product_id}", 300, serialize(product))
        return product

Controlling span volume

Auto-instrumentation creates one span per command, which is right for a service issuing three cache calls per request and badly wrong for one issuing forty. Three strategies, in increasing order of aggression:

Aggregate per request. One span covering all cache work, with counts as attributes. You lose per-key timing and keep the ratio, which is usually the thing you actually query.

class CacheSession:
    """One span per request instead of one per command."""
    def __init__(self):
        self.hits = self.misses = 0
        self.span = tracer.start_span("cache session")

    def get(self, key_template, key):
        raw = redis.get(key)
        if raw is None:
            self.misses += 1
        else:
            self.hits += 1
        return raw

    def close(self):
        self.span.set_attribute("cache.operations", self.hits + self.misses)
        self.span.set_attribute("cache.hits", self.hits)
        self.span.set_attribute("cache.misses", self.misses)
        # Ratio recorded as a bucket keeps it usable as a dimension.
        total = self.hits + self.misses
        ratio = self.hits / total if total else 1.0
        self.span.set_attribute("cache.hit_ratio.bucket",
                                "high" if ratio > 0.9 else "medium" if ratio > 0.6 else "low")
        self.span.end()

Span only on miss. Hits are cheap and uninteresting; misses cause work. Recording a span only when the cache misses cuts volume by the hit ratio — typically 90% — while keeping every span that explains latency. The cost is that hit ratio can no longer be computed from spans, so it must come from a counter metric instead.

Sample cache spans independently. Keep per-command spans but drop most of them in the Collector, retaining all misses and errors.

# collector-config.yaml — thin out cache hits, keep everything interesting
processors:
  filter/cache_hits:
    error_mode: ignore
    traces:
      span:
        # Drop 90% of successful cache hits by hashing the span id.
        - 'attributes["db.system.name"] == "redis"
             and attributes["cache.hit"] == true
             and Hour(TruncateTime(end_time, Duration("1s"))) >= 0
             and IsMatch(span_id.string, "^[0-9a-e]")'
Four strategies, by spans emitted and information kept Four rows. Span per command emits forty spans per request and keeps everything. Aggregate per request emits one span and keeps counts and ratio but loses per-key timing. Span on miss only emits four spans and keeps latency explanation but loses hit ratio. Collector sampling emits about eight spans and keeps a representative sample plus all misses. Spans per request · 40 cache calls strategy spans keeps loses span per command 40 everything nothing — costs the most aggregate per request 1 counts, ratio per-key timing span on miss only 4 latency explanation hit ratio from spans collector sampling ~8 sample + all misses exact per-request counts Most teams want row two in steady state and row one temporarily while investigating a specific cache.

Pipelines, Lua, and cluster hops

Pipelines batch many commands into one round trip. Instrumenting each command inside a pipeline produces spans whose durations are meaningless — they all end when the batch returns. One span for the pipeline with a command count is both cheaper and more accurate.

Lua scripts execute server-side and are atomic. They deserve a span named for the script’s purpose (cache.reserve_stock, not EVALSHA), because the script name is what you will want to group by when one of them starts blocking the single-threaded server.

Cluster redirects are invisible without instrumentation: a MOVED response causes the client to retry against another node, doubling latency. Recording db.redis.redirects on the span turns an unexplained bimodal latency distribution into an obvious slot-migration story.

# Pipeline: one span, not N
with tracer.start_as_current_span("cache pipeline") as span:
    pipe = redis.pipeline()
    for pid in product_ids:
        pipe.get(f"product:{pid}")
    results = pipe.execute()
    span.set_attribute("db.system.name", "redis")
    span.set_attribute("db.operation.name", "PIPELINE")
    span.set_attribute("db.redis.command_count", len(product_ids))
    span.set_attribute("cache.hits", sum(1 for r in results if r is not None))

Choosing a strategy per service, not per fleet

The four strategies above are not a ranking; the right choice depends on what a given service’s cache traffic looks like, and applying one policy fleet-wide is how teams end up with both excessive volume and insufficient detail.

A service issuing three cache calls per request should keep per-command spans. The volume is trivial, the detail is free, and aggregation would hide a genuinely interesting call. A service issuing forty should aggregate by default and switch to per-command spans temporarily when investigating something specific — an override behind a feature flag or an environment variable makes that a restart rather than a deployment.

The deciding number is cache spans per second, not per request. Forty per request at ten requests per second is four hundred spans a second, which is unremarkable; the same forty at a thousand requests a second is forty thousand, which will dominate everything else in your pipeline. Measure before choosing.

There is also a correctness argument for aggregation that has nothing to do with cost. A waterfall containing forty near-instantaneous cache spans is genuinely harder to read than one containing a single span with a count attribute — the eye has to scan past the noise to find the database call that actually took the time. Instrumentation that makes traces harder to read is a net negative even when the volume is affordable.

Whichever strategy you pick, keep the hit ratio available somewhere. If aggregation drops per-command spans, the ratio must come from counts on the aggregate span or from a metric; losing it entirely removes the one number that says whether the cache is doing its job.

Verification

  • Group by cache.hit in the backend and confirm the ratio matches Redis’s own keyspace_hits and keyspace_misses counters. A large discrepancy usually means some code path bypasses the instrumented client.
  • Count spans per request and confirm it matches your chosen strategy — a service that was supposed to aggregate still emitting forty spans means the aggregation wrapper is being bypassed somewhere.
  • Check that misses lead somewhere. A miss span with no subsequent database work means the cache is being read and the result discarded.
  • Confirm no literal keys appear in attributes: grep 'product:8fa21c' over exporter output should return nothing.
Cache spans per second at 500 RPS, by strategy Cache spans per second at 500 RPS, by strategy. span per command 20,000/s; collector sampled 4,000/s; span on miss only 2,000/s; aggregate per request 500/s Cache spans per second at 500 RPS, by strategy span per command 20,000/s collector sampled 4,000/s span on miss only 2,000/s aggregate per request 500/s The bottom two keep the information that explains latency while removing most of the volume.

Common pitfalls

  • Recording the literal key. One distinct value per cached object; it is the cache equivalent of putting a user ID in a metric dimension.
  • Timing pipelines per command. Every command appears to take as long as the whole batch, which makes the slowest-command analysis meaningless.
  • Ignoring connection setup. A client that reconnects per request pays TCP and AUTH costs that dwarf the command itself, and neither shows up unless connection spans exist.
  • Forgetting that misses are the interesting half. Instrumentation tuned to minimise volume by dropping misses removes exactly the spans that explain latency.
  • Treating cache.hit as optional. Without it there is no way to distinguish a healthy cache from a useless one, and the span becomes pure cost.

Related

↑ Back to Instrumenting Databases and Cache Clients