← projects02 / 07 · developer frameworks

Latte

Nanosecond latency profiler: raw TSC timestamps into per-thread ring buffers.

TelemetryProfilingC++Asm
Length
4 min read

Latte live frame latency (wasm, C++20)

loading wasm module...

Latte is a single-header C++17 telemetry framework. Raw x86_64 TSC reads into per-thread, lock-free ring buffers: tens of cycles per sample, no blocking, every statistic deferred to a cold path. std::chrono::now() runs ~150 cycles, two per measurement; the alternatives hash strings or bump shared counters on the hot path, so measuring thread A slows thread B.

01How it works

Hot path only writes. Cold path aggregates, sorts, and filters, once, after sampling stops.

Clock modes

RDTSC: no ordering guarantee. RDTSCP: prior instructions retire first. Full serialization needs RDTSCP + LFENCE, per Intel's benchmarking whitepaper.

ModeInstructionsOrdering guaranteeMeasured Start+Stop cost
Fast__rdtsc()none60.1 cycles
Mid__rdtscp()prior instructions retire first119.8 cycles
Hardlfence + __rdtscp() on both endsfull serialization175.8 cycles

Mode is per call site; Start and Stop can differ. The stack records the capturing mode, and calibration keys on the (start_mode, stop_mode) pair. A global mode would over-serialize everywhere or let reordering smear short measurements.

cpp
void ProcessOrder() {
    Latte::Fast::Start(__func__);   // ~30 cycles: one rdtsc + stack push
    // core logic
    Latte::Fast::Stop(__func__);    // ~30 cycles: rdtsc, pop, delta -> ring buffer
}

Scope identity without hashing

A string literal like "Physics_Engine" has a fixed address, so the pointer is the key. std::map<const char*, RingBuffer>: O(log N) pointer compares, no strcmp, no hashing.

IDs must be pointer-stable. Literals and static const char[] work. A temporary std::string::c_str() silently fragments one scope into several.

Per-thread storage

thread_local stack, map, and ring buffers per thread. First Start(id) allocates that ID's buffer; later calls are allocation- and lock-free. No thread can stall another.

Buffers are alignas(64) and Structure-of-Arrays: timestamps contiguous, separate from metadata, so a timing read pulls only timing data into L1 (Drepper).

65,536 samples per ID per thread (1 << BUFFER_PWR, power-of-two mandatory). Writes overwrite unconditionally: head = (head + 1) & BUFFER_MASK.

Two-phase recording

Start(): push ID, timestamp, mode onto a per-thread SoA stack (64 slots, nested scopes, no linear search). Stop(): pop, delta, write. Whole hot path. Running-stats profilers pay per sample instead.

Cold path forks:

  • DumpToStream(): every thread, outlier filter, mean/median/stddev/skew/min/max/range, self-offset calibration, any std::ostream.
  • Snapshot(id): raw std::vector<Cycles> for one ID across threads.

Outlier filter

A descheduled thread turns a 200 ns event into 100 us; one sample destroys a mean. Plain IQR over raw samples over-corrects: latency distributions are legitimately right-skewed.

Fix: bucket by 1,000, take each bucket's max, compute the IQR cutoff over those maxima. Spikes stand out; the real tail does not. Samples above the cutoff are counted (OUTLIER) and excluded.

02Trade-offs

ChoseGave upWhy it held
direct rdtsc/rdtscp/lfence access, lowest possible read costportability (x86_64 only, GCC/Clang constructs)the target systems are x86_64; an abstraction layer would cost the cycles the project exists to save
zero hashing, zero strcmp on the hot pathflexible identifierspointer-stable literals are a workable discipline in instrumented code
lock-free, atomic-free samplingconcurrent reportingreports happen once at the end anyway; a barrier is cheaper than a lock on every sample
fixed, predictable memory (overwrite ring)unbounded historythe most recent 65,536 samples per scope is enough for distribution analysis
one less compare per sampleStop(id) validationLIFO discipline is enforceable by convention; see below for how that bites

03Benchmarks

AMD Ryzen 5 7600X (6 cores, 4.7 GHz base / 5.3 GHz boost), g++ -O3 -march=native, pinned core, 100,000 iterations per trial, 100 trials, one warm-up batch. Cycles measured via the TSC: probe and subject share a clock.

Latte numbers are Start+Stop pairs. The chart doubles __rdtsc and __rdtscp (mean x2, std dev x sqrt(2)); lfence and std::chrono::now stay single-call.

Each mode lands on its doubled raw primitive: Fast 60.1 vs two __rdtsc 60.2, so push/pop/delta/write costs nothing measurable. Mid sits ~4 cycles over two __rdtscp. Hard is the only mode with visible framework cost, mostly the four fence/read instructions. A full Fast measurement beats one std::chrono::now(): ~13 ns per region at 5.3 GHz.

Calibrated output, simulated trading pipeline, self-offset applied:

#==============================================================================================================#
| LATTE TELEMETRY [TIME][CAL]                                                                                  |
#==============================================================================================================#
| SELF-OFFSET H[Start] x W[Stop]                                                                               |
|                        F             M             H                                                         |
| F                0.21 ns      10.02 ns      10.02 ns                                                         |
| M                0.21 ns      10.02 ns      10.02 ns                                                         |
| H                0.21 ns      10.02 ns      10.02 ns                                                         |
| PULSE           10.02 ns                                                                                     |
|--------------------------------------------------------------------------------------------------------------|
| COMPONENT             SAMPLES       AVG    MEDIAN   STD DEV    SKEW       MIN       MAX     RANGE    OUTLIER |
|--------------------------------------------------------------------------------------------------------------|
| DP_Build_Total              1   38.07 s   38.07 s   0.00 ns    0.00   38.07 s   38.07 s   0.00 ns         0  |
| DP_StateLoop            65536  31.15 us  30.96 us   1.42 us   12.13  29.32 us  95.10 us  65.78 us         0  |
| Sim_Tick_Total           4997 226.79 ns 220.42 ns  76.04 ns    1.40 110.21 ns 821.55 ns 711.34 ns         3  |
| Sim_OrderFlow            4997  43.62 ns  29.63 ns  36.61 ns    2.02   9.59 ns 380.51 ns 370.91 ns         3  |
| Sim_AskLoop              1216   1.03 us 711.34 ns   1.06 us    2.14   0.00 ns   8.30 us   8.30 us         0  |
| Sim_BidLoop              1247   1.12 us 751.42 ns   4.21 us   32.56   0.00 ns 145.96 us 145.96 us         0  |
| Sim_RiskPnL              5000   6.24 ns   9.59 ns   4.67 ns   -0.57   0.00 ns  19.82 ns  19.82 ns         0  |
#==============================================================================================================#

SELF-OFFSET is Start/Stop back-to-back, empty body, per mode pair, subtracted per sample. Hence Sim_BidLoop's skew and Sim_Tick_Total's outliers are signal, not instrumentation noise.

04Sharp edges

Stop(id) ignores its argument and pops the most recent Start(), strictly LIFO. Cross two nested scopes: nothing crashes, one scope's time attributes to the other's ID.

DumpToStream() and Snapshot() during active sampling is undefined behavior. The manager's mutex covers only the global list of per-thread storage pointers. Sequence it: join workers, or hold a barrier, before reporting.

05Next version

  • Buffer size and IQR bucket size become compile-time parameters; right sizes are workload-dependent.
  • ARM via CNTVCT_EL0. Its ordering model differs from RDTSC/RDTSCP, so the Fast/Mid/Hard split needs rederiving.

06Further reading