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¶
dio latency tailshows the current stage distribution. A stage with a p99 an order of magnitude above the others is the one to look at.dio latency tail --since 6hwidens the view across the trading day.dio latency compareagainst an earlier run isolates what changed, andbesttells 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; seebest.
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. |