Timing Simulation and Diagnostics Protection#82
Draft
mrmidi wants to merge 18 commits into
Draft
Conversation
AR Request drains before AR Response, so a target's FCP response block write can arrive before our own command-write acknowledgement has been dispatched. The response itself proves the target received and processed the command; dropping it made the Duet 48 kHz prepublish sequence time out and deferred the audio nub entirely. Accept a validated response for the active write attempt and treat the later local write callback as a harmless stale event. Documented in AVC_RECOVERY_AND_SYNC_ALGO_AND_BUGS.md (committed with the stabilization change). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The IT descriptor ring is free-running and completion accounting measured hardware progress modulo the 48-packet ring, so any refill gap over 6 ms silently discarded whole laps: the wire re-transmitted stale packets at full rate while completionCursor dilated against bus time, dragging the TX producer and the RX replay reader into a permanent all-zero-payload state (2026-07-19 Duet incident: interrupt path died mid-session, the watchdog carried the stream, and 71% of wire packets were stale re-sends). - Recover true progress from the OUTPUT_LAST completion timestamps (ComputeLostLapPackets, one packet per cycle), including the pointer-unmoved whole-lap stall, and reconcile completionCursor, softwareFillAbsIdx_, and completion stamps forward. New lapLossEvents/lapLossPacketsTotal counters and an IT LAP LOSS record. - Fault the transmit context after 16 consecutive IRQ-silent watchdog kicks and log the first watchdog engagement; watchdog-carried streaming re-sends stale ring laps between kicks and is never a valid steady state. - Classify TX replay read failures: re-anchor the reader in place on overwritten history (no frame-cursor realign; skipped entries only shift NODATA placement, legal under IEC 61883-6 blocking), hold the reader on ahead-of-producer, and reserve reader reset plus frame-cursor realignment for genuine RX-domain transitions. Documented in AVC_RECOVERY_AND_SYNC_ALGO_AND_BUGS.md as TX-LAPLOSS-001 (fixed, hardware-validated on a live Duet run) and TX-IRQ-001 (open: why the interrupt path died). Scheme file is xcodegen regeneration. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The Saffire Pro 24 DSP run showed the lap-loss detector's blind spot: completion timestamps cannot distinguish free-running stale re-transmission from a stalled context whose sparse crawl stamps late timestamps (FireBug counted 13 wire packets where the timestamps implied 64k). Classify by coverage: unaccounted progress within the producer's committed lead is reconciled as before; progress beyond it can only end at an uncommitted slot, so fault immediately as context-stalled with the completion accounting untouched. Record ContextControl and the latched IntEvent bits (visible even when masked) in the lap-loss, context-stalled, and watchdog paths as first-fault evidence for the still-open freeze trigger (TX-STALL-001). Document the Saffire incident, TX-STALL-001, and the confirmed fault-propagation gap TX-FAULT-PROP-001. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The Saffire run showed the lap-loss detector phantom-killing a healthy stream (all mod-48 deltas < 48; FireBug 2.24M continuous packets), and DICE was stable before the 2026-07-18 refactors (merge 1bbb70e, no lap-loss logic). Root cause is cross-backend leakage: a shared timingLossCallback_ (AV/C overwrites DICE) and cross-backend RecoverStreaming. references/linux-sound-firewire-stack proves the boundary (per-family recovery, family-blind mechanism, one content callback with errors polled upward); the Focusrite DICE kext corroborates DICE-notification-driven recovery. Records the corrective boundary and withdraws TX-LAPLOSS-001. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
libffado-2.5.0 confirms dice != avc != bebob in ASFW's own idiom: every device is a FFADODevice subclass with per-family streaming/recovery virtuals (lock/unlock/prepare/resetForStreaming), a family-blind libstreaming manager, and one StreamProcessor-per-stream seam. Directs the corrective to per-backend virtual/override recovery rather than a shared callback slot. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Hardware proved the timestamp-based lap-loss/context-stall detector phantom-kills healthy streams on both devices: Saffire and Duet each ran clean (completion cursor tracking the wire exactly, 0 silent packets) until the detector's stale-baseline double-count fabricated a multi- hundred-lap 'stall' on a single coalesced delta=0 read and faulted the context. It also corrupts audio in real time via the sub-fatal reconciliations that jump softwareFillAbsIdx_. Remove ComputeLostLapPackets, DetectLostLapPackets, the Refill reconcile/context-stalled path, the counters, the ContextStalled reason, and their tests. Kept: the backend-agnostic pieces — failure-class replay handling (hold on ahead, no realign) and the watchdog-silence fatal + ctrl/intEvent snapshot. Root cause is elsewhere (TX-IRQ-001 and backend boundary leakage); see AVC_RECOVERY_AND_SYNC_ALGO_AND_BUGS.md. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The existing tools/*.py simulators model three cursors (W write frontier,
E exposure end, C completion) and assume E advances to W + horizon whenever
the producer runs. They contain zero references to the fourth cursor, R --
the RX replay reader against its producer -- so they cannot express a stalled
exposure frontier, and reported the TX geometry as sound.
asfw_sim models all four. Constants are parsed live from the driver headers
(AudioTimingGeometry.hpp, AudioHalBufferProfiles.hpp, RxSequenceReplay.hpp)
by headers.py, with a test that fails if the Python mirror drifts: both 2026-07
triage reports drew wrong conclusions from stale constants.
Findings (tools/asfw_sim/FINDINGS.md), all reproduced by the test suite:
F1 The mechanism both triage reports assert is FALSIFIED. The claim that a
678-packet preparation lead is "structurally unfillable" from a 512-entry
/256-delay replay ring is wrong: the reader advances once per prepared
packet, not per packet index, so reader - producer stays pinned at
-kReadDelay regardless of the lead. A healthy duplex run at HEAD constants
produces zero `ahead`, zero `overwritten`, 99.4% of frames written.
F2 What actually kills the stream is a producer stall past a hard cliff at
78 ms. Past it, zero further host frames are written -- permanently. The
resulting deficit is only ~1000 frames (21 ms) and does not grow: E tracks
W's rate while sitting just behind it, so every frame arrives fractionally
before its packet exists. Transport stays perfect throughout. That is the
observed zombie.
F3 survivable stall (ms) ~= (kReadDelay + kTxDataHorizonPackets) / 8, verified
across six variants. kReadDelay is not a history depth -- it is the
producer-stall recovery budget. HEAD's 256 packets = 32 ms, against the
68 ms watchdog cadence the Duet ran on after its IT IRQ path died.
F5 The 15-576 CoreAudio buffer-size range is a consequence of
kFrameRingFrames = 1536; AudioDriverKit exposes no range setter. Both
devices report an identical bound despite different safety offsets and
latencies, so it is purely ring-derived. `asfw-sim plan-io --frames 4096`
re-derives the dependent chain and checks every header static_assert.
No driver code is changed. The planned kReadDelay fix is still correct but its
justification was not; see F4.
Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
…dget
A scenario is a hypothesis as a file: it names a claim, states the geometry the
claim is about, and declares what must hold if the claim is true (`expect:`), so
a wrong hypothesis fails loudly instead of producing a number someone reads
optimistically. `sweep:` explores instead, over the cartesian product of any
geometry/scenario fields. Overrides are checked against the header's own
static_assert set via derive(); an uncompilable geometry warns, or fails under
`require_valid: true`. tests/test_scenarios.py runs every shipped scenario.
The feature paid for itself on its first run. f3-readdelay-sweep.yaml varied
kReadDelay and kCapacity independently -- every earlier sweep had moved them
together as capacity = 2*readDelay -- and falsified F3:
cliff (ms), rows kReadDelay, cols kCapacity
512 1024 2048 4096
128 62.0 67.4 195.4 451.4
256 78.0 78.0 179.1 435.1
512 - 110.0 146.9 402.9
1024 - - 173.9 339.1
kCapacity dominates: it bounds how far the reader may fall behind before its
history is overwritten, and a stall grows that lag by its own length. kReadDelay
is mildly INVERSE -- at capacity 4096 the cliff falls 451 -> 339 ms as read delay
rises 128 -> 1024, because the reader starts closer to the overwrite edge. No
closed form fits the surface; the old additive law held only on its diagonal.
This inverts the recommended fix. The previously planned change (kReadDelay
256->1024 with kCapacity 512->2048) is strictly dominated by raising kCapacity
alone: more tolerance (179 vs 174 ms) from one constant instead of two, and it
avoids a 32 -> 128 ms bring-up regression, since MarkEstablished() gates deferred
IT start on producer >= kReadDelay. kCapacity 4096 buys 451 ms for 128 KiB.
Two tests in test_stall_cliff.py asserted the falsified law and passed only
because they held capacity = 2*readDelay; both are replaced with tests of the
measured surface. f4-dominated-proposal.yaml keeps the superseded fix as a
regression guard -- it passes in isolation, which is exactly why it was proposed.
Still no driver code changed.
Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Answers the question directly. W > E needs no stall, no bus reset, and no RX epoch change. It is a monotonic ratchet that any RX observation loss drives and that the design has no path back from. The chain, each link in code: 1. DirectAudioReceiveConsumer::ConsumePacket early-returns on packet.payload.empty() (:150), so an errored or zero-length IR descriptor publishes NO replay entry -- while the device really did send those frames. 2. PrepareTransmitSlots consumes exactly one entry per prepared packet (ASFWAudioDriverZts.cpp:241), so a missing entry makes the reader reach the producer and return kAheadOfProducer. 3. `ahead` ships NODATA and holds the reader (:308-317), and NODATA never advances exposedFrameEnd_ (AmdtpTxPacketizer.cpp:209-219). E stands still. 4. W is continuously re-anchored to the device clock via ZTS and keeps advancing. 5. AlignFrameCursorOnce is one-shot (AmdtpTxPacketizer.cpp:126-135) and `ahead` deliberately does not re-arm it -- correct since 81aab17, because re-arming orphans host frames, but it leaves no path back. Each lost observation costs E ~6.8 frames against W, permanently. Measured at 48 kHz with 0.5% RX loss: t(s) W-E ahead align state 4 -2400 0 1 ok <- E leads by exactly the horizon 8 -2112 328 1 ok 12 -816 488 1 ok 16 +440 648 1 SILENT <- W crosses E 36 +6864 1448 1 SILENT Linear, unbounded, never recovers. The load-bearing consequence: kTxExposureLeadFrames = 2400 is NOT a steady-state cushion. It is a one-time budget of ~320 lost RX observations for the entire life of the stream, and nothing replenishes it. At 8000 packets/s, one drop in 800 kills audio in ~64 s; one in 200 in ~16 s. That is "cold start is perfect, dies soon enough", with no TX-IRQ-001 stall required. Growing kCapacity (F4) does not help: the entries were never published, so no amount of retained history contains them. Adds rx_drop_every_cycles and trace_every_cycles to the sim, exposes both to scenarios, and ships f6-rx-loss-ratchet / f6-rx-loss-tolerable. The trace sampler runs at the top of the loop: sampling after the injection `continue` aliased every sample point against the drop cadence and reported one row. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Answers "could the sim catch it?". It cannot observe hardware, but it can pre-compute what each candidate cause looks like in counters the driver already emits, so one ring dump identifies the cause instead of motivating another hardware session. RX loss (F6) and a producer stall (F2) reach the SAME end state -- W > E, align == 1, `ahead` in the hundreds, transport healthy, near-total silence. Counters cannot separate them. The slope of W - E can: cause written ahead reclamp W-E slope/s healthy 99.6% 0 1 -2400 0 rx-observation-loss 45.6% 1208 1 +5200 +311 producer-stall 16.4% 886 2 +1032 -9 replay-ring-churn 99.6% 299 1 -2400 -2 scheduler-latency 99.6% 0 1 -2400 0 Two consequences. `ahead` is NOT diagnostic -- a small replay ring emits 299 of them with audio fully intact, so any triage treating fail=ahead as the fault chases the wrong defect. And a budget being consumed ramps, while a budget spent once goes flat; that is the entire classifier. The ramp inverts to a rate: at a measured 6.79 frames of E forfeited per lost observation, slope / 6.79 = lost RX packets/s. Input is two [PayloadWriter] deficit values and the seconds between them -- no FireBug trace, no full dump. asfw-sim fingerprint # table, recomputed from live geometry asfw-sim diagnose --deficit-start -2400 --deficit-end 380 --elapsed-s 60 The first cut used a noise floor of one IO period per second and classified a -2400 -> +380 ramp as a stall. That hides the dangerous case: a leak slow enough to look stable in a short capture still spends the horizon eventually, since 2400 frames over an hour is only 0.67 frames/s. Floor is now 1 frame/s, and any positive slope reports a time-to-silence rather than a verdict implying safety. Regression test included. frames_lost_per_drop is lru_cached; diagnose() called it per invocation and it costs two full simulations (test module 148s -> 8s). Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
F6 confirmed on a 58-minute Duet session: the deficit ramps +22.6 frames/s,
sampled 23 minutes apart within one session via comp packet counts. Classifier
estimates 3.3 lost RX packets/s (0.042%, one in 2400) -- enough to spend the
2400-frame horizon in 107 s. Supporting: w=0 with outside=0 (silence, not slot
reuse), DATA fraction 0.7497 (transport perfectly healthy), aligned=1 epoch=3,
and gen=197462/131096 -- the predicted MarkHandled divergence from
ASFWAudioDriverZts.cpp:884-896.
Window-length caveat: the first 2.7 s sample of the SAME stream read -2.9
frames/s, i.e. flat, which the classifier calls a stall. The ramp is only
visible over minutes. Short captures will misclassify F6 as F2.
Separately, an asfw://telemetry/snapshot read during the active run issued
GetAVCUnits plus a PHY dump; PHY reg 0 timed out for 115 ms -- past the 78 ms
F2 cliff -- and AV/C escalation then failed exactly as predicted:
IT: Prime failed - committed prefill=306582 must cover 48 descriptors
within 912 slots
[FSM] terminal state=Failed cause=StartTransmit status=0xe00002c9
That confirms AVC-RECOVERY-001 (stale committedEnd reaches Prime) and
AVC-RECOVERY-002 (a 115 ms transient on a healthy device, busResetCount=0,
escalated into CMP teardown, IRM release, terminal Failed).
Operational rule now recorded: during an active audio run use only
asfw_log_query. The snapshot/health/summary/discovery paths issue MMIO on the
driver queue and one PHY timeout exceeds the stall cliff.
Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Adds `asfw.sim.capture.v1` -- a normalised, re-analysable form of one hardware run -- plus an importer for asfw_log_query responses and `asfw-sim capture import|summary|diagnose`. Raw MCP payloads are kept alongside the parsed capture so a parser fix can be replayed against old runs; ad-hoc shell parsing is how a 2.7 s window got read as "flat" while the stream was ramping (F8). `fields` keeps the driver's own key names verbatim so every value stays traceable to the ASFW_LOG format string that produced it; a/b/c pairs expand to key_0/key_1/key_2 while retaining the original string. The first real import found a mechanism neither F2 nor F6 explains. Over 192 s of the committed cold-start capture: lead E-W: +1352 -> -39,860 frames (crossed zero at ~57 s) W rate: 48,000.0 frames/s E rate: 47,785.1 frames/s (4,478 ppm slow) replay failures: ahead=19, reclamped=22 Nineteen `ahead` events cannot account for ~40,000 lost frames at ~6.8 frames each. E is not losing ground in discrete events -- it advances at a slower RATE than W, continuously. Cross-check from the earlier 58-minute session's cumulative counters: prepared=21077837/7037485/28115322 is a DATA fraction of 0.749692 vs the 0.750000 that 48 kHz blocking requires, i.e. 410 ppm slow from cadence alone. F6 and F9 both ramp, so slope does not separate them. The discriminator is whether the `ahead` count can pay for the lost frames at ~6.8 each; here it is short by three orders of magnitude. Why the TX cadence under-produces is open. Committed capture: captures/2026-07-19-duet-coldstart-to-silence.json (1150 records) with its raw MCP payloads under captures/raw/. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
…tatus propagation
…ion) Two clock domains: bus-locked RX/TX (sim loop) vs host IO callback timing. Three ZTS modes: correlated (SimpleIIR), uncorrelated (broken ZTS), perfect. BlockingCadence gains drift_ppm for device audio oscillator mismatch. Diagnose classifies F9 when ahead count cannot pay for the deficit slope. Results: at 0 ppm all modes healthy (structural check); at -4478 ppm uncorrelated collapses (reproduces F9), correlated/perfect stay bounded. Confirms F9's 4478 ppm is not oscillator drift (max realistic ~50 ppm).
… law, IIR sensitivity - Collapse verdict: require 5 consecutive silent IO callbacks at termination instead of a 1-second window fraction (avoids false neg/pos on late events) - F9 classifier: rename ahead→ahead_delta (windowed, not cumulative); capture diagnose path now passes windowed ahead from TxReplay records - Remove falsified kReadDelay+horizon law from cmd_cliff/cmd_sweep (FINDINGS F3) - RX-drop regression test: extend past WARMUP_CYCLES, assert rx_dropped > 0 - IIR alpha sensitivity: new scenario + parametrized test across 0.05–0.90 - README: document three clock rates (FW/Silicon/Intel), 2.3% tick trap, PLL note for pro audio, IIR alpha as sensitivity parameter not measurement
…isect checkpoint) Driver changes (uncommitted work-in-progress): - ASFWAudioDriverZts: re-arm frame cursor alignment on HISTORY_OVERWRITTEN when W > E (deficit-gated self-heal), with selfHealed telemetry field - DiceTxStreamEngine/AmdtpTxPacketizer: expose IsFrameCursorAligned() Diagnostic artifacts (not code): - Triage PDFs, MCP ring captures, log query dumps from 2026-07-19 sessions Checkpoint commit before bisecting for the streaming regression.
mrmidi
marked this pull request as draft
July 20, 2026 06:15
- Replace queue-blocking IOSleep in ApogeeDuetProtocol settle phase with non-blocking ITimerScheduler callbacks - Extend global Duet prefetch deadline from 1200 ms to 5000 ms to cover physical format change time (~2.1s) - Track DuetPrefetchOperation explicitly with epoch and non-blocking timeout guard - Replace IOSleep in AVCDiscovery rescan paths with ITimerScheduler dispatches and mandatory rescanTimersByGuid_ map - Add epoch and active transition checks to prevent stale callback execution - Add ApogeeDuetClockTransitionTests unit test suite
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.
Includes the timing simulation tool, scenarios, deficit slope classification, diagnostics protection for active streaming, and diagnostics status bug fixes.