Skip to content

V2 wire format - #1

Merged
erl987 merged 16 commits into
mainfrom
v2-wire-format
Sep 19, 2026
Merged

V2 wire format#1
erl987 merged 16 commits into
mainfrom
v2-wire-format

Conversation

@erl987

@erl987 erl987 commented Sep 19, 2026 •
edited
Loading

Copy link
Copy Markdown
Owner

v2 wire format, released as 0.2.0

Breaking. A v2 stream needs a v2 decoder and a v1 stream needs a v1 one, in both
directions, so the crate and embedded-etrace move to 0.2.0 together from one tag. A v2
stream is recognised by the TRACE_START frame at its head.

The format

One flat TraceFrame discriminated by event_type rather than a oneof envelope; names
interned into a dictionary; timestamps as deltas; a TRACE_START header carrying the
timebase and source mask. 11–12 bytes per event against v1's 27.

Three things the hardware corrected afterwards:

  • The dictionary is re-emitted every 2 s. Names are registered in the first control
    cycles after boot, so a host attaching to a device that has been up for 55 s received no
    dictionary at all and resolved nothing. A one-way transport cannot observe an attach, so
    the re-emission has to be unconditional.
  • timestamp_ticks is signed. An event is stamped when recorded, not when queued, so
    an ISR preempting a task between those points produces a genuinely negative delta.
    Clamping it to zero drifted the host clock permanently ahead of the device's — at ~416
    ISR events/s, milliseconds per second, which then read as a false reset every couple of
    seconds.
  • Frames are numbered at the producer. Loss at the producer queue used to happen
    before any number existed, so the host saw a contiguous stream with events simply
    absent. The cost is that arrival order is no longer numeric order, so the host decoder
    takes a reorder window.

Visibility

A lost frame used to be invisible except as damage — the SPAN_END never arrived and the
span drew one enormous bar across the gap. Spans open at the hole are now closed and
marked interrupted, and the hole itself becomes a gap row with its frame count,
drawn as a hatched band.

Release readiness

  • Both changelogs written, 0.2.0 dated.
  • Python README corrected: its quick start passed a SequenceTracker where
    decode_tracing_stream takes a TraceStreamState, so the first thing a new user copied
    could not run. The wire-format section still described self-contained frames.
  • Two rustdoc links pointed at names the rewrite removed; cargo doc is now warning-free.
  • release.yml runs pytest and mypy before the PyPI upload. It previously ran nothing,
    and PyPI has no unpublish.
  • CI lints all targets, not just the library, which is why the examples are now clean.
  • README screenshot retaken from a v2 trace.

Verification

70 Rust tests + 3 doctests, 115 Python tests, mypy --strict clean,
cargo clippy --all-targets -- -D warnings clean, cargo fmt --check clean, and
cargo publish --dry-run packages and verifies.

After merging

Tag v0.2.0 to publish both packages. The consuming firmware repository is already
switched from its path dependency to execution-trace = "0.2.0" and
embedded-etrace[diagram]==0.2.0, and does not build until that tag lands.

erl987 and others added 13 commits September 12, 2026 21:36
@erl987 @claude
Write a marker value of zero instead of dropping it
f3ccb25 
`write_tracing_csv` tested the optional fields for truth, so a marker value of
`0` — and a span `deadline_us` or `value` of `0` — was written as an empty CSV
cell. The column is meant to be empty only when the field is absent, and zero
is a legitimate payload: a reason code, a count of nothing, a deadline at the
activation instant.

Downstream an empty cell is indistinguishable from a missing one. `diagram.py`
coerces it to NaN and renders `—`, so the marker that reports "the controller
skipped this cycle, reason 0" arrives on screen with its reason erased — the
one value the marker existed to carry. The decoder was never at fault: it reads
the field with `HasField`, which handles explicit presence correctly.

The tests cover zero and absent separately for both markers and spans, because
the two cases must produce different cells and only their equality was ever
broken.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015X4gKfAJaHxNRqDhhRcwc3
@erl987 @claude
Land the v2 trace wire format: interning, deltas, TraceStart
671c54f 
EXEC-TRACE-002 increment 6, steps 2 and 3 of §18.5. The schema, the encoder
and the Python decoder all move together, since v2 is not wire-compatible
with v1 and nothing decodes a half-migrated stream.

One flat `TraceFrame` carries every frame class, discriminated by
`event_type`, rather than a oneof envelope: proto3 omits unset fields, so an
event pays nothing for the dictionary fields it does not use where an
envelope taxes every event with a tag and a length. Field numbers stay at or
below 15 so every tag is one byte.

Per-occurrence events now carry a dictionary id instead of a name and a delta
instead of an absolute timestamp. The name, source type, priority and
deadline are fixed by the name, so they go out once on a NAME_REGISTERED
frame. Interning is keyed on content rather than on the `&'static str`
pointer §5.5 proposed: by the time an event reaches the encoder the literal's
pointer is gone, and the scan is linear over at most 64 entries, with a
length check before any byte comparison, in the task that owns the wire.

Measured steady state is 11-12 B/event over the delta range the firmware
produces, against the 13 §18.1 predicted from candidate schemas — about a
byte better, because the sequence and the delta both land in their
two-varint-byte range more often than that estimate assumed. A snapshot test
records the whole table and a budget test holds it against §18.1's figures.

Two things the format forced, both recorded in tests:

`decode_trace_frame` returns a `RawTraceFrame` rather than a `TraceEvent`,
because in v2 an event is not recoverable from one frame. Name resolution and
delta accumulation belong to the host decoder, which holds per-stream state;
`TraceStreamState` is where that now lives on the Python side.

Wrapping the sequence at 16 384 weakens reset detection. A restart at zero
only looks backwards when the pre-reset counter was below half the modulus,
so from high in the range a reboot reads as an ordinary gap. The TRACE_START
frame is therefore the reliable reset signal, and a second header mid-stream
now clears the dictionary — a stale entry would otherwise resolve a new id to
the wrong name.

`TraceEvent`, `TraceSink` and the channel element type are untouched, so the
recording layer and its RAM footprint are unchanged; §5.10's reclaim stays in
increment 8 where §9 put it.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01D41mVCmySyLh1Mfn8a2tmK
@erl987 @claude
Re-emit the dictionary periodically so a mid-run attach can decode
3a71ee3 
The first hardware run of the v2 format decoded nothing: every event logged
"name id N was never registered", all spans collapsed onto one <unknown>
lane, and the diagram failed on "row 1012: end_us must be > start_us".

A NAME_REGISTERED frame is sent the first time the encoder sees a name,
which for every name is within the first control cycles after boot. The
device had been up for 55 s when the host attached, so the host received no
dictionary at all and could resolve nothing. §5.5 anticipated this and gave
the job to a "decoder-visible reset", but a host attach is not a device
reset and the device cannot observe one — RTT is one-way. The re-emission
has to be unconditional and periodic, so the encoder now exposes
`encode_dictionary_entry` for a caller to walk.

That means keeping each entry's attributes, not just its name, since the
re-emitted frame has to reproduce the original. A name first seen on a
SpanEnd — its SpanStart dropped upstream under load — is now backfilled
when a SpanStart for it arrives, so a refresh cannot re-send a bare entry
and lose that name's priority for the rest of the run.

Three decoder changes follow, each tested:

A repeated header is no longer a reset. Treating any TRACE_START on a
running stream as a reboot would clear the dictionary on every refresh,
undoing the thing the refresh exists to do. A reboot is identified by the
device clock going backwards, which a refresh never does.

An unresolvable event is dropped rather than renamed. Attributing distinct
unknown ids to one placeholder is what produced the malformed pairs: two
different spans interleaved on one lane, so a SpanEnd closed a SpanStart
belonging to another name. `resolve` returns None and the event is
discarded and counted in `unresolved_events`.

The warning fires once per id. At 1354 events/s the per-event warning
produced thousands of identical lines a second, which is how this
presented in the first place.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01D41mVCmySyLh1Mfn8a2tmK
@erl987 @claude
Sign the timestamp delta; stop discarding the buffer on a reset
a772b60 
The refresh build decoded a readable diagram but the run still showed the
host clock drifting ahead of the device, a false "device reset" every
couple of seconds, and bursts of "Failed to decode TraceFrame".

`record_span_start` reads the clock before the event reaches the producer
queue, so a priority-8 ISR preempting a task between those points puts a
later timestamp ahead of an earlier one in drain order. §5.6 assumed record
order was monotonic and specified an unsigned difference, so an inversion
was clamped to zero while the delta base still moved backwards — and every
inversion added permanent forward drift to the reconstructed clock:

    device 100 -> host 100
    device  90 -> host 100   (delta clamped to 0)
    device 110 -> host 120   (delta 110-90 = 20)

At ~416 ISR events/s that is milliseconds per second, so within seconds the
host clock passed the device's and the periodic header — carrying the true
uptime — arrived looking like the clock had gone backwards.

`timestamp_ticks` is now sint64. Zigzag costs nothing at these magnitudes:
only the 10 µs row of the size table moved, by one byte. Measured on a
stream with an inversion on every control cycle over 10 s: 0 ns drift and
0 false resets, against four before.

`decode_tracing_stream` no longer clears the byte buffer on a reset. The
stream is length-prefixed with no sync marker, so discarding bytes
mid-frame misaligns everything after it unrecoverably — which is what
produced the decode failures at the same millisecond as each false reset.
The frames after a reset are intact; only the decoder state is stale.

Two corrections follow from the same reading. A reset no longer discards
the frame that revealed it: that frame is the first of the new run, usually
the reboot's own header carrying the timebase and mask. And a reboot is now
separated from ordering jitter by a margin rather than a strict comparison
— a reboot drops the clock by the whole uptime, jitter is microseconds, and
without the margin one inverted microsecond blinds the trace for a full
refresh interval.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01D41mVCmySyLh1Mfn8a2tmK
@erl987 @claude
Number frames at the producer, and let the host tolerate reordering
bd89712 
EXEC-TRACE-002 increment 5 (§5.7). A frame is numbered where it is
recorded, not where it is written: one process-global AtomicU32, drawn from
by the recording layer immediately before it hands the event to the
transport, and by the encoder for the two frame classes that were never
recorded — the header and the dictionary entries. The encoder forwards
whatever number an event already carries.

That closes §2.6. Loss at the producer queue used to happen before any
number existed, so the host saw a contiguous stream with events simply
absent; it now leaves a hole. It costs nothing on the wire — the field was
already there, only who fills it changed, and the size table is unchanged.

§5.7 justified this with "the RTIC channel is FIFO, so the transmitted
order still matches". That is the assumption §19.10 already disproved for
timestamps, and it fails here too: the number is taken before the send, so
anything preempting in between reorders it. Two sources, the second larger
than the preemption window §19.10 dealt with — transport frames are
numbered when written and go straight out while events numbered earlier are
still queued, so the distance is bounded by queue depth. The common case is
exact and unavoidable: a dictionary frame is written ahead of the event that
triggered it but numbered after it, inverting a pair on every first sight of
a name.

SequenceTracker therefore takes a reorder_window. A number arriving ahead of
a hole is held rather than treated as evidence of loss; the hole is declared
once something lands more than the window past it, which bounds how late the
report can be. Stragglers close their own hole, and one arriving after its
hole was reported is ignored rather than read as a backwards jump. The trace
stream uses 64, covering the 48-slot channel; single-producer streams keep
zero and report immediately.

The counter is thread-local under cfg(test) — it is global by necessity, so
absolute assertions would otherwise depend on test order — while production
keeps the single atomic. The wrap arithmetic is shared and tested directly,
including across the u32 rollover, which is continuous because 2^32 is an
exact multiple of the modulus.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01D41mVCmySyLh1Mfn8a2tmK
@erl987 @claude
Time the trace from the raw cycle counter, extending the wrap in the …
0d8ddca 
…encoder

EXEC-TRACE-002 increment 7 (§5.8). `TraceSink::now_ticks` — renamed from
`get_elapsed_nanoseconds`, which on this firmware would now be a lie — can
be a single volatile load of the core cycle counter instead of a globally
interrupt-disabled read with a 64-bit divide in it. The encoder is built
for its clock (`new` for nanoseconds, `with_cycle_counter(hz)`), and
`encode_trace_start` no longer takes a timebase: a header disagreeing with
the deltas around it was a state worth making unrepresentable.

§5.8 put the 64-bit extension on the host, reconstructing it "from the
monotonic sequence". Two things since make that the wrong place. The host
no longer sees a monotonic sequence (§20.1), and the absolute timestamps on
the header and dictionary frames — re-emitted every 2 s since §19.9 — would
each be a raw wrapped counter, so the host's clock would jump backwards at
every rollover.

TraceEncoder therefore holds the extension. It runs off the control path,
so §5.8's actual objective is still met; only the bookkeeping moved to the
nearest place that is still cheap. The step is taken in the counter's own
32-bit arithmetic and read as signed, which covers both the rollover and
the small backwards steps of §19.10 without telling them apart. The one
assumption — consecutive readings less than half a wrap apart — is
discharged by the 2 s refresh, which reads the clock.

Duration markers had to learn the timebase too: §5.3's collapsed markers
carry an interval, and dividing nanoseconds by 1 000 is wrong twice over
against cycles, since the divisor is 72 and an interval spanning the
rollover needs 32-bit subtraction. The sink now reports `ticks_per_us` and
`tick_mask`, both defaulted to the nanosecond case, and `ticks_since` does
the subtraction; every call site is unchanged.

Verified against a stream spanning the rollover: 2 000 spans of 500 µs at
1 ms spacing decode to 500.000 and 1000.000 µs with zero deviation.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01D41mVCmySyLh1Mfn8a2tmK
@erl987 @claude
Render trace gaps and cut the spans they interrupt (§5.9)
7ca50c7 
A lost frame used to be invisible except as damage: the SPAN_END that went
with it never arrived, so the span stayed open until the next unrelated end
for that name and drew one enormous bar across the gap and past it.

The decoder now closes every span that was open at the hole, marks it
`interrupted`, and discards the first SPAN_END that arrives for such a name
afterwards rather than pairing it with whatever opens next — which would
invent a span that never ran. The hole itself becomes a GapRecord carrying
the frame count, written as a `gap` row and drawn as a hatched band across
every lane with the count in the label and the tooltip.

Two details that are load-bearing:

  - The spans to cut are those open *at the hole*, not those open when the
    hole is detected. The reorder window of 64 means those differ, and a
    span that started after the hole cannot have been affected by it. A test
    caught this interrupting a healthy gyro_isr span.

  - The gap is placed from the timestamps either side of the hole, which the
    stream state now keeps a short history of, not from whichever frame
    happened to trigger the report. On a real trace that is tens of
    milliseconds of difference.

An interrupted span's end is a lower bound, not a measurement, so it is
exempt from the deadline check and may equal its start; the CSV validator
accepts a zero-length span only when it is marked interrupted, and such bars
get a minimum render width so they stay visible.

etrace-decode now writes gap rows too — without them the CSV shows an
unexplained hole and cut spans with no reason beside them.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01D41mVCmySyLh1Mfn8a2tmK
@erl987 @claude
Size the name registry to the names that exist, not to 64
c8d7fdf 
Under flip-link every byte of .bss is a byte the stack does not get, and the
firmware had just hard-faulted on exception entry for want of them
(EXEC-TRACE-002 §23). This array is the largest thing the trace format puts
in RAM: 64 entries of ~52 B, against 27 distinct names the firmware actually
registers.

40 keeps half again as many entries as anything uses and gives 1 248 B back
to the stack. TracingNameRegistryFull and UNKNOWN_NAME_ID (REQ-T11) still
guard the other side, so overshooting the capacity degrades the trace rather
than breaking it.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Wox8fFjuR68NPpd6sc4dLR
@erl987 @claude
Document the v2 format for the people it breaks
134c8ff 
0.2.0 changes the wire format, and nothing outside the commit messages said
so. Both packages now carry a changelog whose first line is the
incompatibility: a v2 stream needs a v2 decoder either way round, and a
recording must be read by the version that made it.

The Python README had drifted past being merely stale into being wrong. Its
quick start passed a SequenceTracker where decode_tracing_stream now takes a
TraceStreamState, so the first thing a new user copies could not run; the
CSV table was missing `interrupted` and the `gap` row; and the wire-format
section still described each frame as a self-contained TraceEvent, which is
the one thing v2 stopped being. That section is the reason the decoder holds
per-connection state, so leaving it wrong makes TraceStreamState look like
ceremony.

Two rustdoc links pointed at names the rewrite removed and rendered as plain
text on docs.rs. The one in sink.rs was stale twice over: it credited a
`SequenceEncoder` with injecting sequence numbers, when increment 5 moved
numbering to the recording layer precisely so that a loss at the producer
queue leaves a visible hole.

The crate's `include` gains CHANGELOG.md, which is otherwise the one artifact
of this commit that would not ship.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@erl987 @claude
Test the Python package before publishing it, not after
8466de7 
The release job ran cargo test before cargo publish and ran nothing at all
before the PyPI upload, so a tag was the first and only place the shipped
Python package met its own test suite. crates.io allows a yank; PyPI has no
unpublish.

This is the same pytest and mypy gate the Python workflow already applies on
every push, repeated against the version the tag builds.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@erl987 @claude
Lint the tests and examples, instead of only the library
5e8550d 
`cargo clippy --all-targets` reported 61 errors, all of them in test modules
and all of them `unwrap` or `panic!` — the crate denies both because a panic
on the firmware is a hard fault, which is not a risk a test harness runs. CI
passed because it linted only the library, so the examples and tests were
never checked at all.

Allowing the two lints where they are assertions lets CI lint every target,
which is what finds the rest of this commit: two leftover bindings in
encode.rs tests, one of them an encoder shadowed on the very next line, and
an empty format literal in the example — the file a new user reads first and
the one target nothing was checking.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@erl987 @claude
Date the 0.2.0 changelog entries
de55595 
The release workflow takes the version from the tag for Cargo.toml and
pyproject.toml, but not for these, so they are the one place the number has
to be written by hand before tagging.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@erl987 @claude
Show a v2 trace in the README screenshot
a5eb427 
The old one was taken in May 2026 (395c142), so it shows a v1 stream decoded
by the tooling as it stood before increments 5-8 — every change to the format
and the diagram that 0.2.0 releases postdates it.

Same path, so both READMEs and the raw.githubusercontent links in them are
unchanged. The image only reaches crates.io and PyPI once this is on main,
since that is the branch those links name.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@erl987 erl987 self-assigned this Sep 19, 2026
erl987 and others added 3 commits September 19, 2026 15:48
@erl987 @claude
Fix mypy error in assign_lanes by using .at instead of .loc
378ce04 
pandas-stubs cannot type-check DataFrame.loc[idx, "col"] for a scalar
row/column lookup here, since idx is typed as bare Hashable. The .at
accessor is the intended scalar accessor and type-checks cleanly.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
@erl987
Remove outdated section references from comments and documentation
d09d142
@erl987
Update heapless dependency to version 0.9.3 in Cargo.toml
ad63c84
@erl987
erl987 merged commit ee47c12 into main Sep 19, 2026
6 checks passed
@erl987
erl987 deleted the v2-wire-format branch September 19, 2026 15:56
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

No reviews

Assignees

@erl987 erl987

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

1 participant

@erl987