Cassandra Query Tracing

Enable

TRACING ON;
SELECT * FROM users WHERE id = ?;
-- Detailed trace after result

Understanding the trace output

When you run TRACING ON and execute a query, Cassandra records detailed timing information across every phase of the request. The output appears after the query results and shows four critical time points: when the coordinator received the query, when it sent requests to replicas, when replicas responded, and when the coordinator sent results to the client. Between each timestamp, Cassandra also logs latency deltas — the wall-clock time elapsed for that phase.

The trace output is structured as a series of events, each with a millisecond-precision timestamp, the node that generated it, and a description of what happened. For a simple single-partition read at QUORUM, you will see the coordinator's digest-request phase (ask one replica for full data, others for digests), the replica-response phase (collect replies), any digest-mismatch escalation (if replicas diverge), reconciliation (merge conflicting versions), and finally the write-back phase for read repair if needed. Understanding which phase is slow reveals where the bottleneck lives.

Trace schema — sessions and events

Tracing data lives in the system_traces keyspace, which Cassandra creates automatically. Inside, two tables store trace information: sessions holds metadata about each trace (trace ID, query text, client IP, duration), and events holds the detailed event log with timestamps, node IPs, and phase descriptions. You can query these tables directly using CQL to retrieve traces after they have been captured.

Each trace is identified by a unique UUID generated at query time. When you run TRACING ON in cqlsh, the client prints the trace ID immediately after results. Use that ID to fetch the full trace: SELECT * FROM system_traces.sessions WHERE trace_id = <uuid> to see query duration, consistency level, and request type; then SELECT * FROM system_traces.events WHERE trace_id = <uuid> to see every event in order. This two-table schema lets you browse traces after the fact, making it easy to audit slow or divergent queries long after they completed.

Reading a trace end-to-end

Walk through a concrete example. A client reads a partition at QUORUM with RF=3. The coordinator (say, node A) picks two of the three replicas (nodes B and C). The trace log shows: (1) coordinator received the query on node A at T+0ms, (2) sent digest-request to B at T+0.5ms and B responded at T+2ms, (3) sent digest-request to C at T+0.5ms and C responded at T+3ms, (4) digests matched, so coordinator merged the result and returned to client at T+4ms. Total latency: 4ms. If you see unexpected spikes (e.g., one replica responds at T+50ms), the trace pinpoints which replica is slow — either its network link is congested or its local disk/cache is stalled.

Now contrast a digest-mismatch scenario. Same QUORUM read: coordinator asks B for full data and C for digest. B responds at 2ms, C's digest comes at 3ms, but they do not match. The coordinator escalates and requests full data from C, which now takes until T+10ms. The coordinator reconciles at T+11ms (merge by timestamp), then sends write-back to repair node C at T+12ms. Total: 12ms instead of 4ms. The trace makes it obvious: replicas diverged, reconciliation was triggered, and repair overhead added latency.

Diagnostic signatures in trace events

Tracing reveals predictable patterns that diagnose common problems. A slow replica response shows as a large gap between the request-send timestamp and the response timestamp for that replica. The trace will identify which node was slow. A tombstone scan appears as a high cell-count in the events (Cassandra logs how many cells were examined) — if millions of tombstones were scanned to answer a simple query, your partition is too wide or your TTL expiry created dead weight. Cross-datacenter reads show much larger latencies because network round-trip times are higher; the trace makes this visible by tagging events with node addresses — if you see nodes in a different datacenter, you have a multi-DC read.

Speculative retry triggering is another signature: if one replica is slow and the coordinator reaches its speculative-retry timeout, it issues a duplicate request to a second replica in parallel. The trace shows both requests, both responses, and the coordinator returning the faster one. This trades redundant work for reduced tail latency. Finally, if background read repair fires, you will see an extra write-back event to stale replicas — that is read repair healing divergence in real time.

When and where to enable tracing

Tracing is powerful but has a cost. Enabling it globally with TRACING ON in your application will add latency and logging overhead to every query. Instead, always use targeted tracing when debugging. If you suspect a specific query is slow, run it once with tracing on to capture the signature, examine the trace, and turn tracing off. For production troubleshooting, you can also use probabilistic tracing via nodetool settraceprobability 0.01 (or similar), which traces a fraction of queries cluster-wide without slowing every request.

You can also enable tracing at the driver level in your application code. Most Cassandra drivers (Java, Python, Node.js) support query-level tracing: set a flag on the query object to capture the trace for that query alone. This gives you precise control over which requests are traced and avoids the all-or-nothing model of cqlsh tracing. For a production incident, you might enable tracing on a sample of requests from a specific client IP or for queries touching a specific table, using driver-side filtering.

Performance impact and production considerations

Tracing adds measurable overhead. Each event logged requires I/O to write to system_traces tables, and while Cassandra batches these writes, they still consume resources. The impact varies: a simple single-row read might see a 5-10% latency increase when traced, but a complex query that generates many trace events could see 20% or more. Additionally, system_traces data accumulates and must be garbage-collected. By default, traces expire after 24 hours, but you should monitor the keyspace size to ensure it does not grow unbounded.

Never enable global tracing in production without purpose. Instead, use sampling. Configure your driver or the cluster to trace only a small fraction of traffic (e.g., 1 in 1000 queries). This gives you a statistical view of performance without the overhead of tracing every request. When investigating an incident, you can temporarily raise the sampling rate, capture traces, and lower it again once you have the data you need.