feat(transport): capture the raw inbound stream via IBAPI_RAW_CAPTURE_DIR - #758
Merged
Conversation
…_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.
- 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.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Step 3 of
plans/tick-by-tick-reconnect-decode-desync.md. #756 (F1/F2) made a framing desync loud and #757 (F3) made it observable; neither made it capturable, which is what confirming the 2026-07-07 root cause needs.Why the existing recorder can't do this
IBAPI_RECORDING_DIRcallsrecord_responsewith an already-parsed message and re-synthesises a frame. The 4-byte length prefix it writes is one this crate computed, not one TWS sent — and that prefix is precisely the field a framing desync corrupts. The recorder is blind to the only failure worth recording.What this adds
RawFrameTap(src/transport/raw_capture.rs), enabled byIBAPI_RAW_CAPTURE_DIR:transport::sync::read_headerand the newtransport::r#async::io::read_framed_message— record the length prefix beforevalidate_frame_lengthsees it. A prefix rejected asError::InvalidFramenever reaches a caller, but it is the evidence, so it reaches the capture.start_new_segment, so no.binsplices two TCP streams — that would read back as a phantom desync at the seam..bin+.idx. The.binis the inbound stream byte for byte. The.idxcarriesseq,utc_timestamp,offset,declared_lengthper frame, written as soon as the prefix is read — so a frame whose body never arrived still appears, and a desync can be lined up against a[2119]farm notice in the operator's log. The.binhas no clock; that is what the sidecar is for.examples/replay_raw_capture.rswalks a capture, summarises frames by kind, and names the byte offset of the first frame whose prefix cannot describe a frame (exit 1 if it finds one). It re-implements the 4-byte walk rather than calling the crate's reader — the point is to see what the wire said, including frames the reader would refuse.What a capture now settles
Three decisive outcomes, documented in the plan:
replay_raw_capturereports a DESYNC.idxgives the wall-clockF8 — found while wiring this, not fixed here
TcpSocketsets a 1 sSO_RCVTIMEO. If bytes of a frame have already arrived when it fires,Read::read_exacthas consumed them and still returnsErr— its contract discards partial progress.TcpMessageBus::dispatchtreats a read timeout as benign and loops straight back intoread_headerat a shifted boundary. Permanent, silent desync.Verified against a real socket: a peer writing
AA BB, stalling 1.5 s, then writingCC DD EE FFmakes a 4-byteread_exactwith a 1 s timeout returnWouldBlock, after which the next read returnsCC DD EE FF—AA BBare gone.This outranks F2 as an explanation of 07-07: F2 needs the gateway to emit a garbage prefix, F8 needs only a >1 s pause between TCP segments, which is what a data-farm transition looks like from the client. Blocking client only —
AsyncTcpSocketsets no read timeout, and the dispatcher'sselect!cancels the read only on the shutdown branch, which breaks the loop. Recorded as F8 in the plan with a fix sketch; it changes the read loop's error handling and wants its own PR.Tests
15 tests. Format and replay in
raw_capture_tests.rs; tap-below-validation at both reader seams (transport/sync.rs,transport/async/io.rs); end-to-end through the handshake listener over a real socket on both clients, asserting the capture opens with the framed handshake response.src/transport/raw_capture.rsis at 93% line coverage.Note
Captures are unredacted wire bytes — account ids, positions, orders. Called out in
CHANGELOG.md,docs/troubleshooting.md,docs/examples.md, and the plan.Gates
cargo fmt; clippy x3 configs; rustdoc x3 configs;just test(all three legs green);cargo build --examplesx2; both integration crates;just rules-check.Also corrected the recorder's output paths in
docs/troubleshooting.mdanddocs/examples.md— both documentedrequests.txt/responses_<stamp>.txt, which the recorder has never written.Follow-up commit:
/simplifypassCleanup only, no behaviour change to the tap itself.
sink: None,segment: None,disabled: true).Sinknow opens segment 0 eagerly andcapturing_toreturns a disabled tap if that fails, so the flag is gone andsegment: Nonemeans exactly one thing.framed()was a hand-rolledencode_raw_length— which four sibling test files on this branch already import. Replaced, plus arecord_framehelper for the nine open-coded prefix+body pairs.test_disabled_tap_writes_nothingasserted a freshTempDirwas empty, which a disabled tap — never given a directory — cannot affect.src/transport/async/io_tests.rs, beside the function it tests, perdocs/rules/testing/sibling-test-files.md.replay_raw_capturekeys its histogram on aCopyFrameKindinstead of aStringbuilt per frame (~2M allocations on a 1M-frame capture), derivestrailingat print time, and states the real reason it copies the framing constants — they arepub(crate), not "avoiding internals"; the example does link the crate.kill -9; an 8 KiB user-space buffer would lose the tail, which is the evidence), and that the async writes block a runtime worker while the reader mutex is held.Behaviour change outside the tap
MessageRecorder::from_envunwrappedcreate_dir_all, so pointingIBAPI_RECORDING_DIRat an unwritable path panicked duringClient::connect. It now warns and disables recording, matching the policy this PR writes down for the tap two files away: a diagnostic aid must not be the reason a connection fails. Covered by a new test and aCHANGELOG.mdentry.Considered and not done
The strongest review suggestion was to relocate the tap to a
Read/AsyncReaddecorator belowread_exact, on the grounds that the current placement is blind to F8. That premise is wrong: whenread_exactdiscards partially-consumed bytes, the next prefix the tap records is the shifted one, soreplay_raw_capturereports a DESYNC at that offset — F8 is visible. The genuine limitation is only that a.binis not byte-exact against the wire, which the module's# Limitssection already states. A decorator would produce a more faithful artifact and is worth revisiting, but it is a redesign rather than a cleanup, and it would make F8 less conspicuous: the capture would then walk clean while the live client desynced.Also skipped: sharing the timestamp/instance-prefix logic with
MessageRecorder(~6 lines, and the two build different things — a directory vs a filename prefix); dropping the.idxseqcolumn (derivable from line position, but it helpscut/awkpipelines); the index-line allocations (~263 ns against ~3.3 µs of syscall, and only when capturing); and streaming the capture in the example instead offs::read(real for multi-GB captures, but restructureswalk).