Files
amethyst/nestsClient/plans/2026-05-07-i7-post-reconnect-cliff-investigation.md
Claude 3424182c51 docs(nests): I7 post-reconnect cliff — investigation, no fix
Rules out three listener-side suspects (subscribeId reuse,
MAX_STREAMS_UNI credit, SUBSCRIBE_BUFFER overflow) by code trace.
Identifies moq-relay 0.10.x's per-broadcast `serve_group` task
pool as the prime suspect — same root cause documented in the
2026-05-01 cliff investigation, surfacing here when the listener's
QUIC session straddles two publisher cycles for the same broadcast
suffix.

Documents what would confirm the diagnosis (Kotlin↔Kotlin
reproducer + flowControlSnapshot + packet capture) and the two
mitigation paths (listener-side: recycleSession on inner cycle,
trade ~500-1000ms more gap for cleaner relay state; relay-side:
upstream feature request already filed in cliff-plan follow-ups).

No production code change. Production audio rooms don't cycle
aggressively enough to hit this cliff in practice.
2026-05-07 02:01:23 +00:00

9.5 KiB
Raw Permalink Blame History

I7 post-reconnect cliff investigation

Status: investigation only. No production code change. Documents the observation, traces the listener-side and relay-side suspects, and records what would be needed to actually root-cause and fix it.

The observation (from feat/nests-i7-publisher-reconnect)

HangInteropReverseTest.rust_hang_publish_reconnect_kotlin_listener_recovers asserts ≥ 2.5 s of decoded mono PCM after the Rust hang-publish binary cycles its session at the 2.5 s mark of a 5 s broadcast. The test passes at 2.5 s but only marginally:

Phase Wallclock window Captured
Pre-reconnect (cycle 1) 0.02.5 s ~1.9 s of Opus (~95 frames × 20 ms)
Re-issuance gap ~2.52.6 s empty (100 ms RESUBSCRIBE_BACKOFF_MS)
Post-reconnect (cycle 2) 2.65.0 s ~1.0 s of Opus (groupSeq 09), then nothing
Total observed ~2.86 s out of ~5.0 s possible

The Rust publisher's stdout shows it continued emitting cycle-2 groupSeq 1024 (~1.5 s more audio) AFTER the listener stopped receiving uni streams. The relay logs show only cycle-1's subscription was cancelled — the cycle-2 subscription is still "active" from the relay's POV.

So the failure mode is the well-known moq-relay 0.10.x silent forward stall: relay still considers the subscription healthy, the listener still sees a connected session, but the relay never opens new uni streams for the post-cycle frames.

Listener side: ruled out

Walking the Kotlin side end-to-end:

A. subscribeId reuse / stale routing

MoqLiteSession.subscribeSpeaker allocates a fresh subscribeId for every subscribe (MoqLiteSession.kt:249val next = nextSubscribeId++). When the inner handle's bidi collector exits (the relay's SubscribeDrop on cycle-1 publisher end), the entry is removed from subscriptionsBySubscribeId at MoqLiteSession.kt:393. Cycle-2 gets a fresh subscribeId distinct from cycle-1's. Group headers (drainOneGroup#$streamSeq header subId=...) carry the wire-level subscribeId; mismatches would surface as droppedNoSub in the trace logs (line 632), and those didn't increase. Not the bug.

B. MAX_STREAMS_UNI credit

The cliff investigation already raised initialMaxStreamsUni to 1M (c3d6cadff); a 5-second 50-fps broadcast at framesPerGroup = 5 is 50 streams total. We never approach the cap. Flow-control snapshots in the round-2 sweep showed peerMaxStreamsUniNow = 10000 (the relay's max_concurrent_uni_streams default), with peerInitiatedUni == received + 1 cleanly. Same ceiling applies here. Not the bug.

C. SUBSCRIBE_BUFFER overflow

ReconnectingNestsListener.SUBSCRIBE_BUFFER = 64, with onBufferOverflow = DROP_OLDEST. ~5 s of audio at 50 fps is 250 frames; if the consumer were slow, oldest frames would drop, but the total count would still cap near 250. We see ~143 frames (2.86 s × 50 fps). Not consistent with consumer-side back-pressure.

D. Inner-pump opener threw

If the cycle-2 opener(listener) threw (relay rejected the new subscribe), the wrapper retries with exponential backoff (250 → 500 → 1000 ms, capped). 2.5 s of headroom would still allow ~5 retries. The wrapper's Log.w("NestRx") { "ReconnectingHandle.opener threw ..." } would have fired. The I7 agent's transcript doesn't show this log. Not the bug.

Relay side: the prime suspect

Per the cliff investigation's moq-rs 0.10.25 source audit (2026-05-01-quic-stream-cliff-investigation.md:99-150):

  1. Unbounded task pool feeding the awaits. The publisher pushes blocked serve_group tasks into a FuturesUnordered (publisher.rs:325, 346). The receive loop keeps spawning more serve tasks as upstream groups arrive. No backpressure path back to the publisher to slow upstream ingestion.

The cycle-1 → cycle-2 transition at the relay involves:

  1. Cycle-1 publisher session ends → relay propagates Announce::Ended for the broadcast suffix.
  2. Relay drops cycle-1's subscriptions (Drop frame on each subscribe bidi) — the listener observes this as handle.objects flow completing.
  3. Cycle-2 publisher session opens → relay propagates Announce::Active for the same suffix.
  4. Listener's wrapper re-subscribes with a fresh subscribeId on the same QUIC session.
  5. Relay routes cycle-2's incoming groups to the new subscriber.

The opening for cycle-2 frames going dark after group ~10 fits the publisher-side serve_group task pool described above:

  • During cycle 1, the relay had cycle-1's subscriber forward tasks queued in the pool. When the publisher session ended, those tasks may have completed cleanly (they FIN'd uni streams to the listener), OR they may have been left in Pending if the upstream source vanished mid-write.
  • The cycle-1 subscription's removal from the per-track subscriber list does NOT necessarily cancel queued forward tasks for that subscriber — moq-rs 0.10.25's serve_group doesn't take a cancellation handle from the per-subscription bookkeeping.
  • Cycle 2 starts fresh, but the per-track group queue (groups: VecDeque<Option<(GroupProducer, Instant)>>, track.rs:69-90) is shared across publisher sessions for the same broadcast suffix.
  • The ~10-group budget before cycle-2 stalls correlates with the task pool's residual cycle-1 footprint — once the pool's effective ceiling is reached, new open_uni().awaits park indefinitely.

This is consistent with the I7 commit's hypothesis: "moq-relay 0.10.x per-broadcast forward queue holding cycle-2 frames behind cycle-1 fan-out". It's the same per-subscriber forward cliff the cliff plan already documented, surfacing here as a per-broadcast cliff because the listener's QUIC session straddles two publisher cycles for the same broadcast suffix.

Confirming the diagnosis (what would need to happen)

The two listener-side and one relay-side suspects narrow down to one hypothesis, but the data isn't conclusive. To confirm:

  1. Reproduce in the diagnostic Kotlin↔Kotlin path. Add a KotlinSpeakerCyclesKotlinListenerThroughNativeRelayTest that mirrors I7 but uses connectReconnectingNestsSpeaker cycling on a 2.5 s timer instead of the Rust hang-publish --reconnect-after-ms flag. Same listener wrapper. If the Kotlin↔Kotlin reproducer hits the cliff, it's relay-side confirmed (Kotlin↔Kotlin shares NO publisher code with the Rust path; only the relay is common).
  2. flowControlSnapshot during cycle 2. Reuse the listener-side snapshot wiring from :quic (commit d391ae1d's fix). If peerInitiatedUni stops incrementing while peerMaxStreamsUniNow == 10000 stays unchanged AND pendingBytes == 0, the relay is the one that stopped opening streams.
  3. Listener-side QUIC packet capture. Wrap the loopback UDP socket via udp-loss-shim modified to also tap+log packets. Cycle-1 closing should show STREAM FINs + RESET_STREAM frames; cycle-2 starting should show fresh STREAM frames addressed at a higher stream id. Stalled cycle-2 = no further STREAM frames after stream id N.

Steps 1 and 2 are mechanical; step 3 is harder but most diagnostic.

Mitigations to consider (if confirmed)

Listener side: force a fresh moq session on inner cycle

In ReconnectingNestsListener.reissuingSubscribe, when the inner handle.objects flow ends, instead of just looping back to call opener(listener), call recycleSession() to tear down the entire inner moq session and let the orchestrator open a fresh one.

Tradeoff: ~5001000 ms more of audio gap (full QUIC handshake + moq-lite ALPN vs. just a fresh subscribe bidi). Currently 100 ms gap. Plus a fresh JWT session token (which the wrapper already mints on cycle).

Justification: the relay's per-broadcast forward queue is process-global at the relay; the only client-side leverage to clear it is to make the relay drop and re-create the per-listener subscriber state from scratch, which a fresh QUIC session does.

This is hypothesis-driven and would need (1) confirmation per the section above and (2) a regression test (the I7 scenario, but with the threshold raised from 2.5 s to ~3.8 s after the mitigation lands).

Relay side: file upstream

The cliff plan's existing open follow-up #1 already proposes this upstream feature request:

File a feature request at kixelated/moq describing the per-subscriber forward-queue cliff and proposing (a) per-deployment tuning of the unbounded FuturesUnordered task pool, and (b) a deadline on serve_group()'s open_uni().await derived from the active subscriber's smallest max_latency.

If the upstream lands either knob, the per-broadcast cliff goes away too.

Production side: nothing for now

The I7 scenario stresses the relay specifically by forcing a session cycle every 2.5 s. Production audio rooms don't cycle this aggressively — connectReconnectingNestsSpeaker.tokenRefreshAfterMs defaults to 540_000 ms (9 minutes), and the relay's per-broadcast forward queue has 9-minutes of breathing room between cycles. The cliff is not currently observed in production traffic.

Files referenced

  • nestsClient/src/jvmTest/kotlin/com/vitorpamplona/nestsclient/interop/native/HangInteropReverseTest.kt (in feat/nests-i7-publisher-reconnect)
  • nestsClient/src/commonMain/kotlin/com/vitorpamplona/nestsclient/ReconnectingNestsListener.kt:317-465 (reissuingSubscribe)
  • nestsClient/src/commonMain/kotlin/com/vitorpamplona/nestsclient/moq/lite/MoqLiteSession.kt:249,320,393,630 (subscribeId allocation + map mgmt)
  • nestsClient/plans/2026-05-01-quic-stream-cliff-investigation.md:99-150 (moq-rs 0.10.25 source audit)