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.

Parsing and automating trace analysis

Manually reading traces in cqlsh works for single queries but does not scale. For systematic analysis, query system_traces.sessions to extract aggregates: SELECT duration, client FROM system_traces.sessions WHERE keyspace_name = 'your_keyspace' gives you a histogram of query durations. Filter by duration threshold to find slow queries. Once you have identified a slow query, fetch its events and parse them programmatically: extract timestamps, compute deltas, and alert if any phase exceeds a baseline (e.g., replica response greater than 10ms).

Many teams build trace aggregation pipelines. The idea: periodically query system_traces, extract events, and stream them to a time-series database or centralized logging system. Then create dashboards and alerts: if more than 5% of traces show cross-DC reads, page on-call; if digest-mismatch rate exceeds 1%, alert on divergence. This turns tracing from a debugging tool into a monitoring tool.

Tracing vs. other observability tools

Cassandra offers multiple ways to investigate performance. Tracing is query-centric — you capture the end-to-end journey of one request. Slow query logs (if enabled in your application) track queries above a latency threshold but do not give you the internal Cassandra timeline. Histogram metrics (via nodetool tablehistograms) show you aggregate read/write latencies per table but lose the detail of which requests were slow. JMX metrics expose cluster-wide counters (read latencies, cache hit rates, compaction progress) but are aggregates without query-level detail. Driver-level tracing (available in most clients) captures driver-side latency but does not show Cassandra internals.

Use each for its strength: traces when you want the internal Cassandra story; slow query logs when you want application-level detection; histograms when you want a quick per-table view; JMX when you want cluster health; driver tracing when you want to understand client-side delays. For a complete picture of a production incident, you often need all of them together.

Limitations and blind spots

Tracing is powerful but has blind spots. It shows what happened inside Cassandra but not what happened on the client. If a driver connection pool is saturated or the client is experiencing CPU/GC pauses, the trace will show fast Cassandra times but the client saw slow latency — the gap reveals the problem lives in the client. Tracing also does not show compaction activity happening in the background on replicas; if a node is compacting and that interferes with read latency, you see the slow response but not the reason. Finally, tracing at the coordinator node may not show all cross-DC details; if a remote datacenter has a slow disk or network path, the response latency includes that delay but tracing on the local coordinator does not see the internal delays on the remote side.

One more limitation: tracing captures data at write time. If you enable tracing for a write and then later ask what happened to that write, you have the answer in system_traces.sessions/events. But if you forgot to enable tracing, that write is gone — you cannot retroactively trace historical queries. Plan ahead for the queries you want to observe.

Best practices for effective tracing

1. Trace targeted problems, not everything. Determine exactly which queries or patterns are causing trouble, then isolate tracing to those cases. Use driver-level flags or client IP filtering to avoid tracing the entire cluster.

2. Establish a baseline. Capture a few traces of your typical queries when the cluster is healthy. Note the expected latencies and phases. When troubleshooting, compare against the baseline to spot anomalies.

3. Correlate traces across replicas. If a query seems slow, enable tracing on multiple nodes in the cluster and compare their events. You may find that the coordinator was fast but a replica was slow — the replica's trace will show why.

4. Monitor trace table growth. Set an alert on system_traces keyspace size. If it grows unexpectedly, you are wasting disk I/O. Clean up old traces if needed using TTL.

5. Use structured output. Instead of reading traces manually, export them to JSON or a logging system. Structured data makes it easy to aggregate, alert, and correlate with other monitoring data.

What's captured

Timestamps: coordinator receipt, replica request, replica response, coordinator response. Wait times highlight bottlenecks.

System.traces

Tracing writes to system_traces keyspace. Query later. Configurable retention.