Skip to content

fix(transport): name the offending message id in diagnostics and recordings - #757

Merged
wboayue merged 2 commits into
mainfrom
fix/name-unknown-message-id
Aug 9, 2026
Merged

fix(transport): name the offending message id in diagnostics and recordings#757
wboayue merged 2 commits into
mainfrom
fix/name-unknown-message-id

Conversation

@wboayue

@wboayue wboayue commented Aug 9, 2026

Copy link
Copy Markdown
Owner

Follow-up to #756, which added the UNKNOWN_MESSAGE_TYPE_CODE notice but could
not say which id it meant.

The information loss

IncomingMessages::from is lossy — every unrecognized value collapses to the
single NotValid variant — and ResponseMessage::from_protobuf kept only that.
So the id was destroyed at construction, before routing ever saw the frame. By
the time report_unroutable_frame matched NotValid, both of its outputs were
id-less: the notice carried a fixed string literal, and the warn! printed an
empty field list, because a protobuf frame has no fields[0] to fall back on.

During exactly the incident this machinery was built for, an operator would get
N byte-identical notices.

The fix

ResponseMessage now carries message_id alongside kind: the numeric value
kind was resolved from, with the PROTOBUF_MSG_ID offset already removed so
it is the value that was actually looked up. ResponseMessage is pub(crate),
so this is not a public API change. Both constructors funnel through a private
new() that computes kind from it, so the invariant
kind == IncomingMessages::from(message_id) has one home rather than being
asserted by hand in two struct literals.

That is what makes the notice diagnostic rather than decorative: scattered ids
mean the framing slipped; one repeated id means IBKR added a message type.

Two more places the same loss survived

Found by the cleanup pass, both beyond the original scope but the same defect:

  • The wire recorder fabricated the id. recorder.rs reconstructed the
    frame's id with message_type() as i32. That agrees with the arriving id for
    every recognized message — IncomingMessages::from maps a value to the
    variant with that discriminant — but an unrecognized id resolves to
    NotValid, discriminant -1. So IBAPI_RECORDING_DIR wrote -1 into
    precisely the capture worth replaying: an operator recording a desync burst
    lost the one field identifying the fault. Now reads message_id().
  • The handshake reporter had the same gap one phase earlier. The catch-all
    in connection/common.rs logs the kind only, which renders the bare
    NotValid for any unrecognized id — in exactly the reconnect window
    plans/tick-by-tick-reconnect-decode-desync.md is about. It names the id
    alongside the kind now.

Considered and rejected

Recorded so they are not re-litigated:

  • Folding kind into a computed message_type() would undo a deliberate
    cache with 51 non-test call sites.
  • NotValid(i32) is impossible: IncomingMessages is a pub fieldless
    enum used as a HashMap key in both dispatchers, with as i32 casts and
    const arrays. A payload-carrying variant would silently split
    shared-channel lookup, besides being a public breaking change.

Tests

The id surviving both framings — protobuf, which has no fields[0]
fallback, and text, which needs an id at or below PROTOBUF_MSG_ID to reach
that branch at all — plus a recorder regression test, plus id assertions on the
three existing unroutable-frame tests. The thrice-repeated fixture moved to
helpers::unknown_message_frame / UNKNOWN_MESSAGE_ID, so assertions derive
the id instead of spelling it.

Gate Result
cargo test 1353 + 209
cargo test --no-default-features --features sync 1376 + 216
cargo test --all-features 1715 + 321
clippy ×3 configs clean
rustdoc ×3 configs clean
integration crates (sync + async) build
examples ×2 configs build
just rules-check 33 nodes resolve

Still open on this arc

The root cause of the original 2026-07-07 corruption remains unconfirmed
see plans/tick-by-tick-reconnect-decode-desync.md. This makes a recurrence
substantially easier to diagnose but confirms nothing on its own. Remaining
there: the raw-frame tap (F7) and five structural follow-ups.

wboayue added 2 commits August 8, 2026 23:13
The unknown-message-id notice could not say which id it meant.
IncomingMessages::from is lossy -- every unrecognized value collapses to
the single NotValid variant -- and from_protobuf kept only that, so the
id was destroyed at construction, before routing ever saw the frame. An
operator hitting a desync got N byte-identical, id-less notices, and the
warn! printed an empty field list because a protobuf frame has no
fields[0] to fall back on.

ResponseMessage carries message_id alongside kind now: the numeric value
kind was resolved from, with the PROTOBUF_MSG_ID offset already removed
so it is the value that was actually looked up. Both the log line and
the notice text interpolate it.

That is what makes the notice diagnostic rather than decorative --
scattered ids mean the framing slipped, one repeated id means IBKR added
a message type. UNKNOWN_MESSAGE_TYPE_CODE's doc was softened in ae722e8
precisely because it promised that discrimination and could not deliver
it; it now states it and it is true.

Observability policy stays in transport, per the altitude review that
raised this: report_unroutable_frame still decides what is worth
reporting, the parse layer just stops discarding the id.

Tests cover the id surviving both framings -- protobuf, which has no
fields[0] fallback, and text, which needs an id at or below
PROTOBUF_MSG_ID to reach that branch at all.
…ved to

Cleanup pass over 73db598, plus two places the same information loss
survived.

The recorder reconstructed a frame's id with message_type() as i32.
IncomingMessages::from maps a value to the variant with that
discriminant, so the two agree for every recognized id -- but an
unrecognized one resolves to NotValid, discriminant -1. IBAPI_RECORDING_DIR
therefore wrote a fabricated id into exactly the capture worth replaying:
an operator recording a desync burst got -1 where the offending id
belonged. It reads message_id() now.

The handshake catch-all had the same gap one phase earlier -- it logs
{kind:?}, which renders the bare NotValid for any unrecognized id, in
precisely the reconnect window the investigation is about. It names the
id alongside the kind now.

ResponseMessage gains a private new() that computes kind from
message_id, so the invariant kind == IncomingMessages::from(message_id)
has one home instead of being asserted by hand in two struct literals.
That also retires the doubled -1 sentinel in from_text_fields.

Rejected while here, recorded so it is not re-litigated: folding kind
into a computed message_type() would undo a deliberate cache with 51
non-test call sites, and NotValid(i32) is impossible -- IncomingMessages
is a pub fieldless enum used as a HashMap key in both dispatchers, with
`as i32` casts and const arrays.

Tests move the thrice-repeated unroutable-frame fixture into
helpers::unknown_message_frame / UNKNOWN_MESSAGE_ID, so the assertions
derive the id rather than spelling it. Deferrals in plans/.
@wboayue wboayue changed the title fix(transport): name the offending id when a frame cannot be routed fix(transport): name the offending message id in diagnostics and recordings Aug 9, 2026
@wboayue
wboayue merged commit 1ac12a0 into main Aug 9, 2026
4 checks passed
@wboayue
wboayue deleted the fix/name-unknown-message-id branch August 9, 2026 06:44
wboayue added a commit that referenced this pull request Aug 9, 2026
…_DIR (#758)

* feat(transport): capture the raw inbound stream via IBAPI_RAW_CAPTURE_DIR

Step 3 of plans/tick-by-tick-reconnect-decode-desync.md. F1/F2 (#756) made a
framing desync loud and F3 (#757) made it observable; neither made it
capturable.

IBAPI_RECORDING_DIR cannot: record_response is handed an already-parsed
message and re-frames it, so the 4-byte length prefix it writes is one this
crate computed. That prefix is the field a desync corrupts, which makes the
recorder blind to exactly the failure worth recording.

RawFrameTap taps the socket below the framing. Both frame readers record the
prefix before validate_frame_length can reject it, so a prefix that never
reaches a caller still reaches the capture. A reconnect starts a new file, so
no .bin splices two TCP streams. A sidecar .idx carries
seq,utc_timestamp,offset,declared_length — the .bin has no clock, and lining a
desync up against a data-farm notice in an operator's log needs one.

Because the prefixes are the wire's own, a .bin replays through the frame
reader unchanged; tests assert that against both readers.
examples/replay_raw_capture.rs walks a capture and names the first frame whose
prefix cannot describe a frame.

Also records F8 in the plan, found while wiring this: on the blocking client a
1s SO_RCVTIMEO landing mid-frame makes read_exact discard bytes it already
consumed, and the dispatcher treats the timeout as benign and reads on at a
shifted boundary. Verified against a live socket. It needs no corrupt bytes at
all, only a stall, which makes it a better fit for the 07-07 incident than F2.
Not fixed here.

* refactor(transport): /simplify pass on the raw-frame tap

- collapse the tap's three encodings of "off" into one: `Sink` now opens
  segment 0 eagerly and returns a disabled tap if that fails, so `State` drops
  its `disabled` flag and `segment: None` means exactly one thing
- tests use `encode_raw_length` instead of a local `framed()` copy, and a
  `record_frame` helper instead of open-coding prefix+body at nine sites
- `test_disabled_tap_writes_nothing` asserted a fresh TempDir was empty, which
  a disabled tap cannot affect; it now checks what it meant to
- move the async tap seam test to `async/io_tests.rs`, beside the function it
  tests, per the sibling-test-files convention
- `replay_raw_capture`: key the histogram on a `Copy` FrameKind rather than a
  per-frame `String`, derive `trailing` at print, single usage string, and
  state the real reason the framing constants are copied (they are pub(crate),
  not "avoiding internals" — the example does link the crate)
- document why the capture files are deliberately unbuffered, and that the
  async writes block a runtime worker

Also fixes a pre-existing panic surfaced by the review: `MessageRecorder::from_env`
unwrapped `create_dir_all`, so an unwritable `IBAPI_RECORDING_DIR` aborted
`Client::connect`. Same policy as the tap now — warn and disable.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant