Lttng Tracing Root Cause Analysis

LTTng flight-recorder root-cause analysis

When a concurrency bug is intermittent and the assertion fires deep in a hot path, the three usual tools fail in three different ways:

• Static reading can't tell you the interleaving that actually happened.
• printf perturbs the timing — the µs-scale window you're hunting often vanishes when you add I/O — and floods you with output from the wrong threads.
• A debugger stops the world; the race won't reproduce under a breakpoint, and you can't single-step a 192-thread interleaving.

LTTng flight-recorder (snapshot) mode is the tool that fits: near-zero overhead ring buffers per CPU, a global high-resolution clock so events from different CPUs are comparable, and an on-demand dump of exactly the window leading up to the failure. You instrument the culprit to fire a violation tracepoint, dump the snapshot, and abort; then you read the last events before the abort and the interleaving walks you to the cause. This is the tool of last resort for concurrency bugs — reach for it once you've ruled out the cheap explanations.

The setup: snapshot + violation + abort

1. Flight-recorder (snapshot) session, small per-CPU buffers. Snapshot mode keeps a rolling overwrite buffer in memory and only writes to disk when you ask. Start small so the dump is a tight window around the failure:

   lttng create mysess --snapshot
   lttng enable-channel --userspace --subbuf-size=64K --num-subbuf=4 ch
   lttng enable-event   --userspace --channel ch 'myprovider:*'
   lttng start

   64 KiB/CPU is the CLAUDE.md default, and small is right for two reasons, not one: (a) the dump is a tight window around the failure, so it decodes fast and you read only the relevant events; (b) — the one that actually matters for reproducing the bug — a 64 KiB ring stays resident in L2, so the tracepoint stores don't evict the working set into L3/DRAM. A large (multi-MiB) ring pollutes the cache and perturbs the very µs-scale race window you're hunting; the bug can stop reproducing under heavy tracing for the same reason it stops under printf. Keep the ring small to keep the timing faithful. If your per-step tracepoints (below) are high-rate and the interesting window scrolls out before the violation, FIRST cut the event rate — disable the flooding per-iteration event and recover its data another way (e.g. from a core, or a single enriched violation event) — and only bump the subbuf size as a last resort (e.g. 256K × 4 = 1 MiB/CPU), as little as you need; a bigger buffer means both more events to read and more timing disturbance.

2. Emit the violation from the culprit, then snapshot, then abort. At the exact check that detects the corruption, fire an enriched tracepoint, persist the in-memory ring, and crash so nothing overwrites the window:

   if (corruption_detected) {
       FT_TP(violation, /* discriminating state — see below */);
       (void) system("lttng snapshot record 1>&2");
       abort();
   }

   Gate all of this behind a build flag (e.g. -DFT_ENABLE_TRACING) so it compiles out of production and your normal test matrix.

3. Read the window:

   lttng stop
   babeltrace2 ~/lttng-traces/mysess-*/ > trace.txt

Instrumentation discipline

• Tracepoints, never printf — timing matters. The bug lives in a sub-microsecond window; printf's I/O perturbs it out of existence and serializes threads. Tracepoint emission is a few hundred ns into a lock-free per-CPU buffer.

• Make the violation event self-diagnosing. Don't just record "it failed" — record the state that discriminates between hypotheses. For a bad pointer, the high-value fields are usually:

  • the object's identity and a round-trip check (e.g. resolve the object by its own back-reference and compare): if it round-trips to itself the object is valid; if not, it's recycled / stale memory. This one field instantly separates "use-after-free of recycled memory" from "valid object, wrong links."
  • liveness counters (child count, refcount): zero/garbage ⇒ freed.
  • the relevant back-pointers (parent, prev) so you can see which links were and weren't wired.

  These let you classify the failure from the violation event alone, before you even read the surrounding window.

• Add enter/step tracepoints to follow the algorithm. One tracepoint at the entry of the suspect routine and one per iteration of its core loop (carrying the loop variables) reconstruct the control flow that reached the violation — you see the path, not just the endpoint.

• Mind the LTTNG_UST_TP_ARGS limit. lttng-ust caps a tracepoint at ~10 argument pairs. Exceed it and you get a cryptic macro error like unknown type name 'LTTNG_UST__TP_EXPROTOconst' (the arg-count machinery ran off the end). Keep a violation event ≤ ~8 fields; drop redundant ones (e.g. a field that's always NULL at the violation, or one a round-trip already implies). Pointer fields use lttng_ust_field_integer_hex(uintptr_t, name, (uintptr_t) val); counters use lttng_ust_field_integer(...).