Skip to content

Latency journal

The engine already measures every stage of the trading cycle with a histogram profiler: p50, p90, p95, p99, p999, sample counts, overflow, and the slowest sample's cause. The profiler keeps only its most recent window, so a regression is visible on the dashboard while it is happening and then gone.

The latency journal appends every published window to a line-oriented file. That turns "the engine felt slow last night" into a table you can read this morning, and it is what dio latency compare diffs.

The journal is on by default. It runs on one background domain, reads only snapshots the trading domains already publish, and stops itself rather than compete with a trade.

What it records

One row per domain, per stage, per window. Domain is the instrument or the logical owner; stage is the phase.

Source Domain key Stages
Per-asset trading domain symbol (BTC/USDC) orderbook, execution, prep, strategy, cycle
Carry controller <venue>:<instrument> the same five
Overlay instance <venue>:<instrument> the same five
Capital oracle, per asset symbol oracle
Capital oracle, engine-global _oracle pass, balance, fetch
Network, per venue venue (kraken) ws_ping, ws_feed, rest_request, signer
Order executor, per symbol symbol place, amend, cancel
Stop-the-world canary _engine canary

A row is written only when its window has at least one sample, so an idle domain costs nothing.

The canary row is special: it carries the window's maximum pause in every percentile field, because the canary reports one number rather than a distribution. It is useful in tail and best, and is excluded from compare so that a single scheduler stall cannot fail a gate.

Configuration

latency_journal is an optional top-level object. An absent section means enabled with the defaults below.

"latency_journal": {
  "enabled": true,
  "interval_s": 30,
  "dir": "",
  "retain_days": 14,
  "max_total_mb": 128,
  "min_free_mb": 1024
}
Key Default Description
enabled true Journal at all. DIO_LATENCY_JOURNAL=0 overrides without editing the file.
interval_s 30 Seconds between samples. Clamped to at least 5 and at least latency_window_seconds: a profiler publishes only its newest window, so faster sampling would journal duplicates.
dir <data dir>/latency Destination. Empty means /app/data/latency in the image and ./data/latency elsewhere. No other directory is writable under the read-only container root.
retain_days 14 Delete whole files older than this.
max_total_mb 128 Delete whole files, oldest first, while the directory exceeds this size.
min_free_mb 1024 Stop journalling while the data filesystem has less free space than this.

Unknown keys are rejected, like the rest of the configuration schema.

Why both a day count and a size cap

retain_days alone cannot bound the directory: the row count scales with the number of traded assets and with the interval. max_total_mb alone cannot age out a quiet box. Both apply, and whichever bites first wins.

The free-space floor

The journal is deliberately the first thing to stop. The data directory also holds accumulation_state.json, sell_levels_state.json, and the oracle history, so a full disk that blocks a position-state write costs money while a missing percentile row costs nothing. Below min_free_mb the journal pauses and logs one warning; it resumes if space returns.

For the same reason, a journal that cannot create its directory or open its file leaves the engine running. It is the least important thing the process does, and it never blocks startup.

Files

One file per engine start:

latency-<YYYYMMDD-HHMMSS>-<pid>.jsonl

A nightly restart is therefore the natural rotation boundary, and two engines sharing a host cannot interleave rows. Files are opened append-only and never rewritten; retention deletes whole files, oldest first.

The process exits with the file open, which is safe because every window is written as it is produced. A SIGKILL (or docker rm -f) can truncate the last line; readers skip unparsable lines, which is the point of line-oriented JSON.

Record format

One JSON object per line:

{"g":"a1b2c3d4e5f6","t":1794160359.4,"d":"BTC/USDC","s":"prep","n":1234,
 "p50":0.4,"p99":2.1,"p999":5.0,"mx":9.2,"ov":0,"w":1794160359.2,"c":"gc"}
Field Meaning
g Build identity from DIO_GIT_SHA, when the deploy sets it. Absent otherwise.
t Unix time the row was written.
d Domain key.
s Stage.
n Samples in the window.
p50, p99, p999 Percentiles in microseconds; sub-microsecond values are fractional (0.4 = 400 ns).
mx Slowest sample in the window, microseconds.
ov Samples beyond the profiler's tracked range.
w Profiler window end; used to ignore a re-sampled window.
c Cause of the slowest sample when known (often the GC cause), else null.

p90 and p95 are omitted deliberately: bytes are the binding constraint on the prod data directory, and a run-to-run comparison needs tails and maxima.

Reading it

The dio binary reads journal files without booting the engine, so the verbs run on a copy of the files anywhere, including inside the engine container.

On a deployed host the data directory is readable only by the account that owns it, and the container's root user runs without CAP_DAC_OVERRIDE. Read the journal as that uid, or copy a run out with the daemon:

docker exec -u 1000 dio_engine dio latency tail --dir /app/data/latency
docker cp dio_engine:/app/data/latency/ /tmp/latency/

dio latency tail

Current value per domain and stage: the newest sample inside a time window.

dio latency tail
dio latency tail --since 10m --domain BTC/USDC
dio latency tail --file latency-20261110-220000-1.jsonl
Flag Default Description
--dir DIR <data dir>/latency Directory of journal files.
--file FILE unset Read one file instead of a directory.
--since DUR 1h Window. 30s, 10m, 2h, 1d, or bare seconds.
--domain NAME unset One domain.

dio latency best

The lowest p99 ever recorded per stage, with when it happened and the build it came from.

dio latency best
dio latency best --dir /app/data/latency

best is an observation, not a target. The minimum across runs is usually the least representative run: an asset was idle, the market was quiet, or the box was otherwise unloaded. A run with a lucky minimum also has unrepresentative sample counts. Treat best as the drift view and never gate on it.

dio latency compare

Two runs side by side, sorted by regression.

dio latency compare old.jsonl new.jsonl
dio latency compare /app/data/latency/previous /app/data/latency
dio latency compare baseline.jsonl today.jsonl --tolerance-pct 5 --gate

Each argument may be a .jsonl file or a directory. A directory resolves to its newest run that actually contains samples, skipping the zero-row file a crash can leave behind. That one rule covers both "compare these two exact runs" and "compare today against the baseline folder".

Flag Default Description
--tolerance-pct N 10 A stage beyond this p99 increase counts as a regression.
--min-samples N 100 Skip stages below this many samples in either run.
--gate off Exit 1 when any stage regresses past the tolerance.

A run is summarized as the median of its per-window p99, plus its peak, rather than a single window, because one window is noise. Stages idle in either run are excluded, so a quiet asset never reports a spurious swing.

Exit codes: 0 success, 1 gate failure, 2 usage error or unreadable input.

Finding a bottleneck

  1. dio latency tail shows the current stage distribution. A stage with a p99 an order of magnitude above the others is the one to look at.
  2. dio latency tail --since 6h widens the view across the trading day.
  3. dio latency compare against an earlier run isolates what changed, and best tells you how far the current value is from the best ever seen.

The cause column links a spike to a collector event without correlating logs by hand. A large max with an empty cause usually means a scheduler stall rather than GC; compare it with the _engine/canary row in the same window.

Gating a change

Do not gate CI on two prod journals. Real market data drives run-to-run variance that swamps a code change, so a p99 delta from two nights is mostly weather. Gate on deterministic replay instead: replay one recorded trace, journal during the replay, and compare --gate against a pinned baseline. With fixed input, the same delta is the code change.

Keep the two artifacts separate:

  • latency/baseline/ — a deliberately pinned run. This is the gate.
  • latency/best/ — never gates; see best.

Promote a run to the baseline only when it is comparable: same asset set, sample counts within roughly 20% of the incumbent for each stage, and the same commit family. Auto-promoting the raw minimum would peg the gate to a lucky run and make it permanently red.

Hot-path guarantee

The journal adds no work to the cycle:

  • It runs on one detached domain pinned to background affinity at idle priority, like the stop-the-world canary. It competes with no trading core.
  • It only reads published snapshots through a lock-free atomic. No lock is taken on a trading path. The one shared mutex, guarding the profiler table, is held only long enough to copy the table and is also taken by domain startup, so contention is confined to a domain restart.
  • No fsync. One buffered append per interval; roughly 7 KB every 30 seconds.
  • Every write is wrapped. A failure increments a dropped-row counter and the engine carries on.

Environment variables

Variable Effect
DIO_LATENCY_JOURNAL 0/false/off/no disables journalling without editing config.json.
DIO_LATENCY_DIR Overrides latency_journal.dir; useful for tests and sidecars.
DIO_GIT_SHA Recorded as g on every row so best can name the build. Optional.