You add a tracing library that writes one 32-byte record per event to a lock-free buffer. Measured latency rises from 1.9 to 2.4 microseconds and the 99.9th percentile doubles. Explain the observer…

Question

You add a tracing library that writes one 32-byte record per event to a lock-free buffer. Measured latency rises from 1.9 to 2.4 microseconds and the 99.9th percentile doubles. Explain the observer effect concretely and describe an instrumentation design that costs under 20 nanoseconds per event.

Accepted Answer

The observer effect here is that the tracing writes evict the hot path's own data from L1 and add a timestamp read and a branch to every event, and an instrumentation design that costs under 20 ns writes a fixed-size record into a per-thread ring with no formatting and no shared state. A 32-byte record per event at 8 events per message writes 256 bytes, which is four cache lines per message, and those lines displace order book lines from a 32 KB L1, so the next book read misses and costs 80 ns that the trace never shows. The timestamp source matters: a clock_gettime call through the virtual dynamic shared object is 20 to 25 ns, while rdtsc is about 20 cycles, and a serialising variant costs more. The 99.9th percentile doubles because the buffer occasionally crosses a page boundary and takes a fault, or the consumer thread's reads pull lines into the shared state. The cheap design uses a per-thread ring buffer, preallocated and pre-faulted, aligned so records never straddle a line, holding raw binary fields with the formatting done offline, an rdtsc timestamp converted to nanoseconds after the fact, and non-temporal stores so the trace does not pollute the cache. Sample rather than trace everything when even that is too much, and keep the sampling decision branch-free.