Skip to content

Timing Simulation and Diagnostics Protection#82

Draft
mrmidi wants to merge 18 commits into
mainfrom
feat/big-python-sim
Draft

Timing Simulation and Diagnostics Protection#82
mrmidi wants to merge 18 commits into
mainfrom
feat/big-python-sim

Conversation

@mrmidi

@mrmidi mrmidi commented Jul 19, 2026

Copy link
Copy Markdown
Owner

Includes the timing simulation tool, scenarios, deficit slope classification, diagnostics protection for active streaming, and diagnostics status bug fixes.

mrmidi and others added 16 commits July 19, 2026 11:27
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>
…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
mrmidi marked this pull request as draft July 20, 2026 06:15
mrmidi added 2 commits July 20, 2026 18:47
- 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
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