hda_tone: the judge refuses multi-stream sessions, and a dropped cpal stream waits a bounded time on soundd and then lets go by Japabu · Pull Request #641 · ToyOSOrg/ToyOS

Japabu · 2026-09-30T17:17:22Z

hda_tone has redded on every T14 boot since #536 with "soundd filled 104 period(s) the tone client had not covered". The 104 periods were never the tone's.

Root cause

Where the 104 came from. hda_client_stall, the job after the tone in the testcases boot, stalls its client 8 times for 13 periods each (starve_max=13), so 8 × 13 = 104.
- On Every QEMU ceiling is at most three times what its test takes; wedges end in seconds; two LAN boots ride the talking boot #638, its stream opened at 5.657 s, 2 ms after the tone job's exit record (5.655 s). soundd removed the tone's stream only at 5.661 s, after fading it out.
- So soundd never reached clients=0 between the two jobs. soundd counts one stats window across every client it holds and flushes it only when the last client leaves. The tone's last window (4.459 s to 6.460 s) therefore carried the stall's first 3 stalls (39), and the next window the other 5 (65).
- job_window (tests/common/audio.rs) ends a session at the first clients=0 line after the job's spawn, so it summed both windows into the tone.
Why Storage: file servers for DATA, the log and the boot volume; the kernel's NVMe and FAT go #536 made it deterministic. Measured across 19 T14 console logs as the time from the tone job's exit record to the next job's opening stream, against soundd's removal of the tone's stream:
- After Storage: file servers for DATA, the log and the boot volume; the kernel's NVMe and FAT go #536 (7 boots): 2 to 4 ms, against a removal at 5 to 6 ms. The next stream opens first on all 7.
- Before Storage: file servers for DATA, the log and the boot volume; the kernel's NVMe and FAT go #536 (12 boots): 12 to 69 ms on 9, so the removal came first there. On the other 3 the next stream opened first, and hda_tone redded the same way. f5c8026, the red filed in issues/audio/hda-tone-reads-underruns-on-the-t14-where-its-judge-wants-none.md, is one of them.
- The change in Storage: file servers for DATA, the log and the boot volume; the kernel's NVMe and FAT go #536 (read from its code, not measured): before it, spawn opened each binary through vfs::lock().open_backing, which first ran writeback::drain_held to the boot stick. logd wrote /log through the kernel's FAT under the same lock. Storage: file servers for DATA, the log and the boot volume; the kernel's NVMe and FAT go #536 moved /log and /boot to fsd and took the drain out of Vfs::open_backing_identified. A job boundary no longer waits on a USB write, so it now fits inside soundd's fade.
soundd is right. It fades a closed stream out before removing it (retain_active, userland/soundd/src/mix.rs), and its stats windows are defined to span every client it holds (toyos-mixer/src/stats.rs). The judge assumed each job's stream had a soundd session to itself, and nothing ensured that.

The fix

The judge refuses a shared window (8b522da, dfc9da0). Once another job's stream joins a session, no line soundd writes can take its counts apart. So job_window now refuses, by name, any window whose sessions are not one stream each, instead of summing another job's counts into its own job.
- It counts the window's connects and its removals against its sessions. A stream soundd already held at the job's spawn connected outside the window and is removed inside it, so the removals are what catch it.
- The tolerance is unchanged.
- tests/checks/audio.rs stages three windows the judge must refuse:
  - a shared window with zero underruns, which the old judge passes;
  - a tone whose window ended at an earlier stream's clients=0 before its own stream connected (the review's case);
  - a tone beside a stream soundd held at its spawn.
A dropped stream is one soundd has let go of, or it is refused by name. cpal toyos-0.18.0 is at 29180f7, pinned in userland/Cargo.lock and tests/toyos-rust-tests/Cargo.lock.
- (18f2db2) The ToyOS host's stream thread used to send the close and end, so Drop returned during soundd's fade. It now reads the signal pipe until soundd closes it, filling what soundd asks for meanwhile with silence, since that is past the stream's end.
- The tone job's stream is therefore gone before the job exits, and the next job's stream cannot share its session. Signal-pipe EOF is the one event a client has for this. The SDK's AudioStream::close is fire-and-forget, and toyos/src is outside this brief.
- (061f134) Drop waits on the stream thread's end, still the pipe's EOF, but for at most soundd's 5 ms fade in whole periods plus the stream's ring of 8 periods: 1280 frames, 29.02 ms at 44100 Hz. A mix loop that has not run for a whole ring has let the device play out everything it was given.
- Past the deadline, Drop reports HostUnavailable through the error callback and returns: "soundd did not let go of the closed stream within 29.024943ms, its fade and a ring of periods".
- The thread's end reaches Drop through a channel whose sender only the thread holds. An unwinding data callback therefore ends the wait the same way the pipe's end does.
- (29180f7) Once Drop has given up, the stream thread ends at soundd's next signal instead of filling silence until soundd lets go. Dropping its AudioStream closes the stream's connection and signal pipe, and soundd removes a stream on either.
- (29180f7) The app's data callback is called until Drop gives up, as at 7e9775d and 18f2db2, so soundd's fade ramps from the app's audio and not from zeros. Drop gives up by taking the callback from under the lock each fill calls it with, so it is not called once Drop has returned. A fill after that is silence.
- (29180f7) The stream thread reports nothing once the stream is dropped. It reads STATE_DEAD under the error callback's lock, which a Drop that gives up takes after storing it, so no DeviceNotAvailable lands after Drop has returned.
- soundd's fade and its ring depth are copies in the fork; the open's answer does not carry them. That is the defect issues/audio/cpal-backend-hardcodes-the-format.md records, the fork compiling in soundd's numbers, and it is folded in there.
cpal_drop_unreleased, a guest test (tests/toyos-rust-tests/src/bin/cpal_drop_unreleased.rs).
- The binary answers a cpal client's open as soundd does and reads its close. Then it holds the signal pipe open and does not write it until the client's Drop has come back.
- Its client builds a stream and drops it unplayed. It must get the refusal through its error callback before Drop returns, and says it on its stdout.
- The server then writes one signal, and the stream's connection has to end while the client lives. The client exits only once the server closes its stdin.
- At 18f2db2 the client waits forever. At 061f134 the stream thread fills that signal with silence and waits on, and the server waits with it. No sound plays and soundd is not involved.
play_tone reads its error callback (tests/toyos-rust-tests/src/tone.rs). It drops its stream after the tone and asserts that the callback never ran. hda_tone and soundd_log_stall therefore red by name, through job_passed, on a refusal from a healthy soundd. Both are metal-only (tests/toyos.rs:379,382).
issues/audio/hda-tone-reads-underruns-on-the-t14-where-its-judge-wants-none.md is deleted. Its exit condition is the T14 PASS below.
issues/audio/hda-client-stall-reads-one-resume-where-its-judge-wants-two.md records what the head's T14 log shows, below.

Measured on the T14 at `1621eb5`

The orchestrator's --metal hda_tone run (issuecomment-5917167316), orch/logs/641-T14-hda_tone.log lines 535–556, in log order:

{2026-09-30 18:18:54 5.670 soundd} soundd: client 0 removed (closed)
{2026-09-30 18:18:54 5.670 soundd} soundd: wakes=645 completions=415 submitted=415 underruns=0 drains=0 max_wake_lat_us=80 max_batch=1 clients=0 deferred=0 starve_max=0 worst_irq_late_us=62 worst_pickup_us=18 worst_empty=1 worst_batch=1 late_wakes=0
[2026-09-30 18:18:54 5.670 cpu5 tid=1] exit: test_rs_audio_tone tid=1 code=0 cpu=29ms (after 49 like it suppressed)
[2026-09-30 18:18:54 5.670 cpu4] exit: test_rs_audio_tone pid=11 code=0 cpu=2ms
[2026-09-30 18:18:54 5.672 cpu7] spawn: /system/bin/test_rs_hda_client_stall pid=12 …
{2026-09-30 18:18:54 5.673 tid=1 soundd} soundd: opening stream: 44100Hz 2ch fmt=0

The tone's client 0 removed and its clients=0 flush come ahead of exit: test_rs_audio_tone. The stall's first stream opens 3 ms after that exit.
The judges at dfc9da0 read this log as follows, in a scratch host test that is not committed:
- audio_idle_suspend: PASS
- hda_tone: PASS
- shipped_client_departures: PASS
- hda_client_stall: FAIL, "soundd resumed 1 time(s) — the second stream did not find a suspended daemon, so nothing here tests a resume:"

Gates

At 597d60a, cpal at 29180f7:

gate	exit
`cargo run -- --build-only` against the local fork clone before pushing it	0
`cargo test --test toyos-build -- --list` against the local fork clone (builds the guest crate; lists `cpal_drop_unreleased`)	0
`cargo run -- --build-only` at the pushed pin (userland's and the guest crate's cpal both from the 29180f7 checkout)	0
`cargo test --test toyos-build -- --list` at the pin	0
both of the above with `pin-061f134.patch` applied (the guest crate built from cpal's 061f134 checkout; lists `cpal_drop_unreleased`)	0, 0
`cargo metadata --locked` in `userland/` and in `tests/toyos-rust-tests/`	0, 0
`cargo run -- --ci host`	0
`cargo test --test toyos-checks`	0 (27 passed)

The judge is unchanged since dfc9da0, where its mutations were measured:

gate	exit
`metal_audio_judges` with `streams != sessions` made `streams > sessions`	101: "a tone whose window ended before its stream connected passed a log it has to refuse"
`metal_audio_judges` with the removal count dropped	101: "a tone beside a stream soundd held at its spawn passed a log it has to refuse"
`metal_audio_judges` with the judge change reverted and the staged shared window kept (at `1621eb5`)	101: "a tone another job's stream joined passed a log it has to refuse"

The orchestrator's runs at dfc9da0 (issuecomment-5918082157):

cpal_drop_unreleased: 0, in 150 ms.
The same with pin-18f2db2.patch: 1, timed out at the 300 s ceiling.
The whole suite: 0, 503 of 503 passed.
T14 --metal hda_tone: 0, PASS. T14 --metal shipped_client_departures: 0, PASS.

No guest or T14 run has been made at 597d60a.

Negative controls:
- For the bound: pin-18f2db2.patch pins cpal back to 18f2db2 in both lockfiles. That is the base whose unbounded wait the review measured, and it keeps the guest test.
- For ending the stream thread: pin-061f134.patch pins cpal back to 061f134 in both lockfiles and keeps the extended guest test. It is shown to build and has not been run.
- For the tone fix: revert-fix.patch reverts the whole change onto 6e1f166. The T14 exited 1 with it (issuecomment-5917167316).
Independent oracles:
- Real hardware: the T14 at 1621eb5 above, and at dfc9da0 hda_tone and shipped_client_departures passed.
- Recorded real failures: 20 T14 logs run through the judge at dfc9da0, in a scratch test that is not committed. These are Every QEMU ceiling is at most three times what its test takes; wedges end in seconds; two LAN boots ride the talking boot #638's testcases readback and 19 console captures, 7 from after Storage: file servers for DATA, the log and the boot volume; the kernel's NVMe and FAT go #536 and 12 from before.
  - hda_tone's verdicts are round 1's on every log: 9 PASS, and 11 refused as a shared window.
  - shipped_client_departures passes on all 20.
  - hda_client_stall has the same 2 PASS and 18 FAIL as round 1. On 11 of those FAILs the removal count now names the shared window, "connected 2 and removed 3 stream(s)", where round 1 said "resumed 1 time(s)". On those boots the tone's removal lands inside the stall's window.

Unsure

hda_client_stall stays red, and this does not fix it. Its issue now carries the head's log.
- Its judge wants its first stream to find soundd suspended.
- On the head's T14 log, soundd suspends 23 to 24 ms after the last removal, and the stall's first stream opens 3 ms after the tone job exits.
The mechanism in Storage: file servers for DATA, the log and the boot volume; the kernel's NVMe and FAT go #536 is inferred from the code. Only the interval shift is measured.
The deadline's margin is not measured. The two dfc9da0 T14 logs (orch/logs/641r2-r2-T14-hda_tone.log, …-shipped_client_departures.log) hold 10 real-soundd cpal drops, 5 per boot: the tone, the stall's two streams, and the two tones from null_sink_client_exits. Each ends in client N removed (closed). The count of did not let go lines is 0 in each log. The logs stamp in milliseconds and do not record the close, so no margin can be read from them.
A soundd that never signals again after a give-up leaves the stream thread blocked on the pipe until the process exits. The thread holds the stream's connection, so soundd's control thread sees no disconnect. soundd signals on its timer even while a device completes nothing, so this needs a soundd whose mix loop has stopped.
No gate places a fill between the drop and the give-up. That the app's audio fills the ring during Drop's wait rests on the code. A QEMU test could reach that window only with a clock.
An app data callback that blocks also blocks the give-up, because the take waits on the fill's lock. At 7e9775d Drop joined the thread and waited on the same callback.
play_tone's assert has no negative control that has been run. It reads only on metal.

🤖 Generated with Claude Code

https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L

The T14 has redded `hda_tone` on every boot since #536 with "soundd filled 104 period(s) the tone client had not covered". None of them were the tone's. `hda_client_stall`, the next job in the boot, stalls its client eight times for 13 periods each (`starve_max=13`): 104. On #638 its stream connected 2 ms after the tone's job exited, while soundd was still fading the tone's stream out (it removed it 4 ms later), so soundd never reached `clients=0` between the two. soundd counts one window across every client it holds and flushes it only when the last one leaves, so the tone's last window carried the stall's first three stalls (39) and the next window the other five (65), and `job_window`, which ends a session at the first `clients=0` line after the job's spawn, read both as the tone's. No line soundd writes can take such a window apart, so the judge now refuses a window whose sessions are not one stream each, by name, instead of summing another job's counts into its job. The host check stages that window with no underrun at all, which the judge passed. Run against 20 T14 logs, #638's `testcases` readback and 19 console captures of 7 boots after #536 and 12 before it: every `hda_tone` FAIL, on every boot after #536 and on the 3 before it where the next stream connected first, becomes this refusal; every PASS stays one; `shipped_client_departures` reads the same on all 20. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L

cpal's ToyOS host at 18f2db2: dropping a `Stream` returns once soundd has let the stream go, which it says by closing the stream's signal pipe, where it used to return as soon as the close was sent, inside soundd's fade. A job that drops its stream and exits now leaves nothing for the next job's stream to share, which is what `hda_tone`'s window needs to be the tone's. Why the next job's stream got there first once #536 landed, measured as the interval from the tone job's exit record to the next job's `opening stream`: 2 to 4 ms on all 7 T14 boots after it, against the 5 to 6 ms soundd takes to fade and remove a stream; 12 to 69 ms on 9 of the 12 boots before it, and f5c8026, one of the 3 that lost, redded the same way. What held a job boundary before #536 is read from its code, not measured: `spawn` opened the next binary through `vfs::lock() .open_backing`, which first drained the write-back queue to the boot stick (`writeback::drain_held`), and logd wrote `/log` through the kernel's FAT under the same lock. #536 moved `/log` and `/boot` to fsd and took that drain out of `open_backing`. `hda_client_stall` stays red: its judge wants its first stream to find soundd suspended, and soundd suspends about 23 ms after the previous stream is removed, once the pipeline has played out (`issues/audio/hda-client-stall-reads-one-resume-where-its-judge-wants-two.md`). `issues/audio/hda-tone-reads-underruns-on-the-t14-where-its-judge-wants-none.md` goes: its exit condition is `hda_tone` PASS on the T14 at the head that lands this. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L

Japabu · 2026-09-30T18:22:12Z

Orchestrator runs at 1621eb5 (logs orch/logs/641-*.log):

job	command	patch	exit	line
whole	`cargo test --test toyos-build --`	—	0	`test result: ok. 502 passed, 502 total (400.7s)`
T14	`--metal hda_tone`	record rows for `boot.testcases` (the run would write them otherwise)	0	`PASS hda_tone`
T14, fix reverted	`--metal hda_tone`	`revert-fix.patch` + the same rows	1	`FAIL hda_tone: soundd filled 104 period(s) the tone client had not covered, on a client that keeps its ring full:`

Japabu · 2026-09-30T18:35:33Z

Review of #641 at 1621eb5, round 1.

Gate: CI host success at 1621eb5 (run 36758084460, job 110033342217). T14 --metal hda_tone exit 0 at head and exit 1 with revert-fix.patch (issuecomment-5917167316). Ready for review.

Net git diff --shortstat origin/main...HEAD: +37 −53. Production: two lockfile lines moved, plus +5 in the fork. Tests: +35 −1. Issues: −50.

Brief

Root cause: holds. The deleted issue's own log shows the stall's client 1 connected at 6.254 before the tone's client 0 removed at 6.258. Its window sums to 0+39+65 = 104, which matches 8 stalls of 13 periods each. Every QEMU ceiling is at most three times what its test takes; wedges end in seconds; two LAN boots ride the talking boot #638's readback is not in the tree, so that part rests on the PR's word.
Fork: upstream-mergeable in shape. It is one ToyOS-only hunk in src/host/toyos/mod.rs, and toyos/toyos-abi come from crates.io ranges, not paths. It is pinned in both lockfiles that name toyos-0.18.0 (userland/Cargo.lock:608, tests/toyos-rust-tests/Cargo.lock:340), and no gitlink names it. ToyOSOrg/cpal toyos-0.18.0 is at 18f2db2. Its wait is BLOCKER 1.
Yes, it can hang: BLOCKER 1.
The refusal fails in one direction only: BLOCKER 2.
It does not matter for this branch. ToyOSOrg/cpal's activity for toyos-0.18.0 shows one fast-forward push, 7e9775d→18f2db2, and no force push. wt/toyos-tonefix was created at 1621eb5 and never moved. No published hash was lost. The rule's letter was broken (reset --soft plus a recommit is an amend), but the reason for the rule (a cited hash) never came into play. Fix BLOCKER 1 with a new fork commit on top, never another reset.

BLOCKER

ToyOSOrg/cpal@18f2db2:src/host/toyos/mod.rs:242 — while audio.wait_and_fill(..).is_ok() {} has no bound and no refusal by name. It ends only when soundd removes the stream, not merely when soundd runs. Removal needs two things: the control thread must read the close (userland/soundd/src/control.rs:290), and the mix loop must mix ramp_frames into freed buffers (userland/soundd/src/mix.rs:468, toyos-mixer/src/gain.rs:72,81) before retain_active closes the pipe (mix.rs:130). At 7e9775d, Drop returned at the next signal or at once. Three hangs are new: (a) a device that stops completing, where soundd still wakes on its armed timer and signals (mix.rs:261, :400), so this loop never ends; (b) a soundd whose soundd-ctrl thread has ended while its mix thread runs, which can happen because the ToyOS target sets no panic strategy and so unwinds per thread (rust/compiler/rustc_target/src/spec/base/toyos.rs); (c) a paused or never-played stream beside a mix loop that stopped signalling. Shipping code reaches it: doom's I_ShutdownSound (userland/doom/src/sound.rs:403) and toybox tone at the end of main (userland/toybox/src/tone.rs). The PR's "the existing dependency, extended by one fade" is false. Required: keep waiting on the EOF itself, but bound it by a deadline derived from soundd's fade and period; when the deadline passes, refuse by name through error_callback and return. Also show a guest arm in which the stream's server never closes the signal pipe: it must hang to the harness ceiling at 18f2db2 and return with the named refusal at the new pin.
tests/common/audio.rs:45 — this mutation keeps cargo test --test toyos-checks metal_audio_judges green: - if streams != sessions { / + if streams > sessions {. No staged case has fewer connects than sessions. That is the direction that refuses a window which ended at an earlier stream's clients=0 before the job's stream connected. For the tone, such a window holds no tone stream and passes with underruns=0. Add after tests/checks/audio.rs:67: judged("a tone whose window ended before its stream connected", tone_on_metal, &format!("{configured}{}{{0.900 soundd}} soundd: client 0 removed (closed)\n{}{}{next}", spawn("test_rs_audio_tone"), stats(0, 0, 0), session(stats(0, 1, 0), "closed", stats(0, 0, 0))), false)?;. It must be green at head and red under the mutation.

NOTE

tests/common/audio.rs:41 — connects are counted only from the job's spawn. A stream soundd already held at the spawn, and still held when the job's stream connects, gives one connect per session and passes. Counting removed ( lines against sessions as well closes this. It cannot happen to the tone today, because the job before it, test_rs_audio_idle_suspend, plays nothing (tests/toyos.rs:2052). Until then, line 14's "refused unless each is one stream" claims more than the check does.
issues/audio/hda-client-stall-reads-one-resume-where-its-judge-wants-two.md — it does not record what this PR found. At this head the tone's stream is gone before its job exits, and the stall's first stream opens about 2 ms after that exit. soundd suspends 20 to 25 ms after the last removal (8.565→8.585 and 9.755→9.780 in the issue's own log). So client_stall_on_metal's premise, that the first stream finds soundd suspended, now holds on no boot. The issue also lacks the red line at this head; the PR states that line for old logs only. Add both as measured evidence from the head's testcases log.
PR evidence — orch/logs/641-* holds the head's T14 testcases log, but only hda_tone's verdict is reported. Cite from it the tone's client 0 removed and clients=0 lines ahead of exit: test_rs_audio_tone: that measures the mechanism rather than inferring it from one PASS, and 9 of 12 boots before Storage: file servers for DATA, the log and the boot volume; the kernel's NVMe and FAT go #536 passed by race alone. Also report the verdicts of hda_client_stall, shipped_client_departures and audio_idle_suspend from the same boot. The pin changes every cpal client, including the shipped tone that shipped_client_departures spawns twice.

REMOVE

PR body, Gates table, last row "requested of the orchestrator, not run here" — stale: issuecomment-5917167316 ran it.
PR body "The deletion landed in 8b522da, the commit before the one whose message names it." — narration.
PR body "The lockfile bump changes only cpal's line. cargo update --precise also re-picked …" — provenance narration that the diff already states.
PR body "Every cpal client on ToyOS … now drops in one fade plus at most one mix-loop period more than before." and the Unsure bullet "Drop now blocks until soundd closes the signal pipe … extended by one fade." — false (BLOCKER 1).
tests/common/audio.rs:16-17 "What keeps jobs apart is cpal's ToyOS host, whose Drop returns only once soundd has let the stream go." — states a fork's behaviour that the lockfile pin moves; the refusal holds without it.
issues/audio/hda-client-stall-reads-one-resume-where-its-judge-wants-two.md:16 "Its cause is not measured; whether the judge or soundd is wrong is open." — false after this PR.

SEND BACK

ToyOSOrg/cpal `toyos-0.18.0` moves to 061f134 in both lockfiles that name it. At 18f2db2 a dropped `Stream` waited for soundd to close its signal pipe with nothing to bound the wait, so a soundd that stopped serving the stream held doom's `I_ShutdownSound` and `tone`'s exit for good. `Drop` now waits at most soundd's fade in whole periods and then the stream's ring of periods, 1280 frames or 29.02 ms at 44100 Hz. Past that it reports `HostUnavailable` through the error callback, naming soundd, and returns. `test_rs_cpal_drop_unreleased` is that case in a guest. The binary answers a cpal client's open as soundd does, reads the close, and then holds the signal pipe open without writing it. Its client, a stream built and dropped unplayed, has to come back from `Drop` with the refusal and exit 0. At 18f2db2 the client waits forever. No sound plays and soundd is not involved. `job_window` counts removals against sessions as well as connects. A stream soundd held at the job's spawn connected outside the window and is removed inside it. The audio checks stage both directions the count must refuse: - a tone whose window ended at an earlier stream's `clients=0` before its own stream connected, red under `streams > sessions`; - a tone beside a stream soundd held at its spawn, red without the removal count. The client-stall issue gets what this branch's T14 log shows. The deadline's fade and ring depth are copies of soundd's, filed. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L

Japabu · 2026-09-30T19:21:20Z

Orchestrator runs at dfc9da0 (logs orch/logs/641r2-*.log):

job	args	patch	exit	line
new arm	`cpal_drop_unreleased`	—	0	`PASS cpal_drop_unreleased (150ms)`
new arm, cpal pinned back to 18f2db2	`cpal_drop_unreleased`	`pin-18f2db2.patch`	1	`FAIL rs::cpal_drop_unreleased: timed out after 300s, with the guest still talking 5s ago (355 console line(s) while it ran) — it was working and did not finish`
whole	(none)	—	0	`test result: ok. 503 passed, 503 total (291.4s)`
T14	`--metal hda_tone`	record rows for `boot.testcases`	0	`PASS hda_tone`
T14	`--metal shipped_client_departures`	same	0	`PASS shipped_client_departures`

Japabu · 2026-09-30T19:36:30Z

Review of #641 at dfc9da0, round 2.

Gate: CI host passed at dfc9da0 (run 36762597666, pull_request, headSha dfc9da0). issuecomment-5918082157 reports:

cpal_drop_unreleased exits 0 at the pin.
Pinned back to 18f2db2, it exits 1 at the 300 s ceiling.
The whole suite passes 503/503.
The T14 passes hda_tone and shipped_client_departures at dfc9da0.

Ready for review.

Net size (git diff --shortstat origin/main...HEAD): 8 files, +238 −54.

Production: two lockfile lines. The fork is +64 −5 over main's pin 7e9775d. 061f134 adds the bound round 1 required; accepted.
Tests: +177 −1.
Issues: +59 −51.

Round-1 BLOCKERs

CLOSED: the unbounded Drop wait. ToyOSOrg/cpal@061f134 waits on the stream thread's end, which is still the pipe's EOF, for RELEASE_WITHIN, then refuses by name through error_callback. The measurement is issuecomment-5918082157: cpal_drop_unreleased passes in 150 ms at the pin and hangs to the ceiling (exit 1) pinned to 18f2db2.
CLOSED: the streams > sessions mutation survived. The staged case is at tests/checks/audio.rs:68-78. The PR's gates table shows metal_audio_judges exiting 101 under that mutation, naming the case, and CI host runs it green at dfc9da0.

Brief

29.02 ms comes from copies of soundd's constants, not from soundd.
- FADE_FRAMES copies toyos_mixer::ramp_frames (toyos-mixer/src/shape.rs:160).
- RING_PERIODS copies slot_count = num_buffers (userland/soundd/src/main.rs:175), which is 8 on every backend: kernel/src/drivers/hda.rs:80, toyos-abi/src/virtio_sound.rs:16, main.rs:76.
- Only the period is checked against the open's answer (fork mod.rs:203).
- The copies agree today: ⌈220/128⌉ = 2, and (2+8)×128 = 1280 frames = 29.024943 ms.
A slow soundd on the T14.
- The bound counts from Drop, not from soundd's read of the close.
- A healthy release is about 3 periods: the stream thread's next signal (≤1 period), soundd-ctrl reading the close, the 220-frame fade into the next two freed periods, then the EOF. The bound allows 10. The 3 is estimated from the code; round 1's 5–6 ms from exit record to removal fits it.
- A mix loop 7 periods late has drained the device, and the audio judges already red on that.
- Only the mix thread enters the RT band (mix.rs:230; set_current_rt acts on the current thread, kernel/src/syscall/proc.rs:115). soundd-ctrl (main.rs:195) and cpal's stream thread are both on the path and outside the band. A starved one draws the refusal without any drain.
- A refusal still ends in a fade: soundd starts the ramp on whichever departure it sees first (userland/soundd/src/client.rs:145-152), and it removes the stream when the process exits.
- The visible effects of a refusal:
  - tone and doom print audio error: ….
  - On the metal sequence, the next job's stream can land in the tone's session, and hda_tone refuses that by name.
- The tree records soundd late by more than two pipelines while still running (toyos-mixer/src/shape.rs:14-17; 106654 us under doom, issues/audio/desktop-session-put-26ms-of-silence.md:32). So a refusal is reachable on a loaded desktop.
- So there is no refusal at every normal exit. There is a refusal that no gate reads (NOTEs 1 and 2).
The fork: upstream-mergeable and pinned.
- Every hunk is ToyOS-only: src/host/toyos/mod.rs, and target_os = "toyos" joining the two cfg lists at src/host/mod.rs:123,160 that gate the shared error_emit.
- There is no path dependency.
- toyos-0.18.0 is at 061f134, fast-forwarded from 18f2db2; the fork's activity log shows no force push.
- It is pinned in both lockfiles that name the branch (userland/Cargo.lock:608, tests/toyos-rust-tests/Cargo.lock:340), and no gitlink names it.
The filed issue: NOTE 6.

BLOCKER
None.

NOTE

tests/toyos-rust-tests/src/tone.rs:51 — no gate reads a refusal on a healthy soundd — play_tone's error callback only prints.
- hda_tone catches a bound that is too short only when the tone's late release loses the race with the stall's open, which came 3 ms after the tone's exit on the head's T14 log.
- const RING_PERIODS: u32 = 0; in the fork sets a 5.8 ms bound against a release of about 3 periods (estimated). It refuses many drops, but the release still usually lands before the next open, so hda_tone stays green.
- Fix: set an Arc<AtomicBool> in the callback, drop(stream) after the sleep, and assert! that it is unset.
- hda_tone's job_passed("test_rs_audio_tone") then reds by name on any refusal, on metal only (audio_tone is no QEMU test, tests/toyos.rs:379).
PR body, Unsure, "The deadline's margin is not measured at this pin" — report the count of did not let go lines in the two dfc9da0 T14 logs.
- Those logs hold every real-soundd drop of the testcases boot: the tone, the stall's two streams, and the two tones from null_sink_client_exits.
- The 503-test QEMU run drops no stream on a real soundd.
ToyOSOrg/cpal@061f134:src/host/toyos/mod.rs:332-333 — after a refusal, the stream thread keeps soundd's stream, the ring, and one wake per signal for the life of the process — the compromise is recorded only in the PR body.
- The wakes come because soundd still signals on its timer when a stopped device completes nothing (mix.rs:261,400).
- Record it in issues/ with an exit condition, or end it: let the tail loop stop once Drop has given up, and the dropped AudioStream lets soundd remove the stream on disconnect.
ToyOSOrg/cpal@061f134:src/host/toyos/mod.rs:258-263 — the error callback can run after Drop has returned.
- Drop can give up while the thread is still in the PLAYING wait. A later EOF, from soundd being gone, then emits DeviceNotAvailable.
- The STATE_DEAD check guards only the data callback; guard this emit with it too.
ToyOSOrg/cpal@061f134:src/host/toyos/mod.rs:237-240 — Drop can put a step before soundd's fade.
- The silence also replaces fills made during Drop's wait. At 7e9775d and 18f2db2 those fills were the app's audio.
- If the ring is nearly empty at Drop, which needs a late stream thread (doom's ring has run dry on record, issues/audio/desktop-session-put-26ms-of-silence.md:51-56), soundd's 220-frame fade lands on these zeros, after a step down from at most one period of the app's audio.
- The case is narrow, but preventing that step is what the fade is for.
issues/audio/cpal-drop-deadline-mirrors-soundds-fade-and-ring.md — its facts are right, but it duplicates an existing issue and names no owner.
- Both numbers are copies. StreamOpenResponse.slot_count reaches AudioStream::open and stays private (toyos/src/audio.rs:216-220). No message carries the fade. The remedy needs toyos/src and the audio protocol, which the brief fenced out.
- It is the same defect as issues/audio/cpal-backend-hardcodes-the-format.md: the fork compiles in soundd's numbers instead of reading the open's answer.
- Fold it into that issue, together with NOTE 3's compromise.

REMOVE

PR body, "Requested of the orchestrator at dfc9da0 (orch/tonefix/r2/jobs.txt):" and its four bullets — stale: issuecomment-5918082157 ran them.
PR body, "The T14 rows at dfc9da0 are requested." — stale, for the same reason.
PR body, "so past that point soundd is not serving the stream" — false.
- The bound also spends the waits of cpal's stream thread and soundd-ctrl, and neither is in the RT band.
- The tree records soundd late by more than two pipelines and still running (toyos-mixer/src/shape.rs:14-17).
ToyOSOrg/cpal@061f134:src/host/toyos/mod.rs:28, ": past the fade and one ring, soundd is not serving the stream" — false, for the same reason.

LAND AFTER NAMED CHANGES

ToyOSOrg/cpal `toyos-0.18.0` moves to 29180f7 in both lockfiles that name it. Once a `Drop` has given up on soundd, the stream thread ends at soundd's next signal, and the stream's end lets soundd remove it. The error callback reports nothing once the stream is dropped, so it cannot run after `Drop` has returned. The fills made during `Drop`'s wait are the app's audio again, so soundd's fade ramps from it and not from zeros. `play_tone` drops its stream after the tone and asserts that its error callback never ran. `hda_tone` and `soundd_log_stall` now red by name on a refusal from a healthy soundd, which no gate read before. `cpal_drop_unreleased` writes one signal once the client's `Drop` has come back with the refusal. It then needs the stream's connection to end while the client still lives. At 061f134 the stream thread fills that signal with silence and waits on, and the server waits with it. `cpal-drop-deadline-mirrors-soundds-fade-and-ring` is the same defect as `cpal-backend-hardcodes-the-format`: the fork compiles in soundd's numbers instead of reading them from the open's answer. It is folded into that file. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L

Japabu · 2026-09-30T20:06:54Z

Orchestrator runs at 597d60a (logs orch/logs/641f-*.log):

job	exit
`cpal_drop_unreleased`	0
whole	1 — `502 passed, 1 failed`; the one red is `iommu_virtio_platform`, the known ordering flake that #639 fixes
T14 `--metal hda_tone`	0
T14 `--metal shipped_client_departures`	0

CI host success at 597d60a.

Clean merge. Main's one new timed wait, `handler_post_without_a_pass`'s `drain_until(30 s)`, and its new shared member `cpal_drop_unreleased` were written against the width-scaled budget; the next commit brings them under this branch's ceiling rule. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L

…ll, and main's new wait is under the rule - `ceiling_self_check`'s two walks step `since`, `died` and `quiet` by 100 ms, the read loop's poll of a silent guest, instead of by whole seconds. At whole seconds a backstop one second short, `(ceiling * 2).max(ceiling + GUEST_QUIET - 1 s)`, passed both walks: at `since = 5` the walk reached 19 s at quiet 14, and 19 is not past 19. It now fails at `since = 4.2 s` ("timed out after 19s"), EXIT=101. - The walks' comment goes: "any point" claimed more than the walk checks, and the rest restated the loops. - `handler_post_without_a_pass`'s drain, from main's #634, was 30 s under the width-scaled budget. The test took 3-4 s in #634's whole runs (4 s in 634r6), so it is 12 s. - `cpal_drop_unreleased`, #641's new shared member, took 111 and 138 ms in #641's whole runs, so the 5 s shared default covers it and it needs no row. - `deaf_cpu_hold` keeps its fixed 20 s. A binary test-runner spawns holds no `logread`: test-runner hands down its namespace, and `logread` is a `SysCap` duplicate, not a namespace entry. logd serves no reader port on `tests/testcases`. The only record the hold could read is logd's file under `/log`, which gives no notification, so waiting on it would be a sleep-and-reread poll. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L

…toyos-noredlist #588 landed first, and its `usb_stick_left` arms `usb-transport-break`, `usb-reset-moves`, `usb-reset-moves-after` and `usb-reset-moves-configured` again, its T14 row (`usbbreak`) arms `usb-transport-break`, and its metal record carries the `usbbreak` rows. Those stay, with `msc::transport_break`, `msc::reset_moves`, `RECOVERING` and `Quiet::Staged`. Everything else this branch deleted with `usb_transport_break` (90ecefe, b5c59cb, 402107b, 9ebf080) stays deleted: no test on either side arms it. Conflicts, every hunk: - `kernel/src/actuator.rs`, two hunks. First: main's eight USB rows. Kept `usb_transport_break`, `usb_reset_moves`, `usb_reset_moves_after` and `usb_reset_moves_configured`, with `usb_reset_moves`' doc losing its citation of the deleted `usb_transport_break`; dropped `usb_transport_offline`, `usb_reset_break`, `usb_transport_break_owed` and `usb_transport_break_flushed`, armed only by the deleted `usb_transport_break`, `log_flush_retry` and `partition_claim_departure`. Second: dropped `watch_window` (`blocking_read_window`, deleted in dc62efc), kept #634's `handler_post`. - `kernel/src/drivers/xhci/wait/msc.rs`, fourteen hunks, misaligned by #588's rewrite of the file. Resolved as main's file with this branch's deletions applied to it: `Asks` and `bot`'s `asks` argument at its five call sites; `transport_break`'s owed and flushed half (`WROTE`, `FLUSHED`, `AFTER_A_FLUSH`, `wrote`, `flushed`, their calls in `MscDevice::wrote` and the flush, and `arm`'s argument), so `arm` reads `usb-transport-break` alone; `return_silent` and its hook in `served`; `reset_break` and the wrapper around `climb`, whose body `climb_until_in_step` carries again; `short_read` and its hold and release around the data phase; `staged` and its checks in `bot`, the bad signature, the withheld CBW, the gone port and the unanswered wait; the bind's `slow_return` stall and INQUIRY staging, and `slow_return` itself; `read_serial`'s short ask. `reset_moves`, its three holds and `RECOVERING` are main's as they stand. - `kernel/src/watch.rs`, one hunk: dropped the `window` module (`watch-window`), kept #634's `handler_post` module. - `toyos-sched/src/watch.rs`, one hunk: the same, `window` dropped and `handler_post` kept. - `src/lib.rs`, one hunk: kept #652's `pub mod n2`, dropped `pub mod redlist`. - `tests/common/power.rs`, one hunk: main's only change there renamed `transport_break_chain`'s doc to `usb_stick_left`; its one caller is the deleted `usb_transport_break`, so it stays deleted. - `tests/common/usb.rs`, one hunk holding main's whole `usb_transport_break` region. Kept #588's `Held`, `usb_stick_left`, `a_stick_that_left_under_its_rung`, `transport_break_on_metal`, `transport_break_recovered` (which `tests/checks/usb.rs` judges) and `broke_on`; the rest is `usb_transport_break`'s and stays deleted: `a_read_whose_first_wait_spent_its_budget_goes_out_again`, `serial_short_is_not_read`, `cpu_of`, `line_with`, `Moved`, `a_stick_its_reset_moved_carries_on`, `abandoned_write_is_taken_offline`, `no_command_was_refused`, `port_gone_is_left_to_the_teardown`, `control_requests`, `command_blocks`, `every_reset_is_followed_by_a_test_unit_ready`, `is_a_rungs_configuration`, `every_port_reset_is_followed_by_a_test_unit_ready`, `every_reset_is_followed_by_both_clears` and `transport_gives_up`. - `tests/toyos.rs`, five hunks. `MACHINE_TESTS`: kept `usb_stick_left` and #634's `handler_post_without_a_pass`; dropped `usb_transport_break`, `xhci_full_speed_device` (5e42235), `blocking_read_window` and `user_copy_races_munmap` (7ea6be1). `METAL`: kept #588's `usb_stick_left` row. Dispatch: kept `usb_stick_left` and `handler_post_without_a_pass`; dropped `usb_transport_break`, `xhci_full_speed_device` and `smp_failed_ap_leaves_no_hole` (aedcf17). Outside the conflicts: - `kernel/src/drivers/xhci/wait/mod.rs`: `Quiet::Staged` and its line come back, which `transport_break::take` answers with; the auto-merge had taken 9ebf080's deletion. The `reset_break` and `return_silent` hooks stay deleted. - `src/metal.rs`: `FLASHABLE`'s `usb-transport-break` row comes back (b5c59cb took it), since `usb_stick_left`'s T14 arm flashes it. - `issues/kernel/a-held-disk-waits-for-a-pass-no-cpu-takes-when-every-cpu-is-in-a-call-on-it.md`: records `4f2bea143`, this merge's second parent, as the tree holding #588's version of `usb_transport_break`, in place of the instruction to record it. - `issues/boot-media/logd-ends-the-boots-log-on-one-refused-create-and-nothing-durable-says-so.md`: drops its citation of `power::transport_break_chain`, deleted in 90ecefe. The `rust` gitlink is main's. On this tree: `cargo run -- --build-only` exit 0; the kernel's `cargo check` for x86-64 and AArch64, bare, with `boot-actuators` and with `boot-actuators,test-actuators`, exit 0 each; `cargo test --test toyos-build --no-run` exit 0, no warning. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L

The branch was at 649ea51 (#641). Three landings since sit under it: #642 (dc8212c), #659 (c1c5048) and #655 (5daab30). Two content conflicts, each main deleting what this branch's hunk stood beside: - kernel/src/object/ops.rs, close_ends_polls: #655 deleted the log's and the keyboard's close actuators, whose two arms this branch's `Process(_) => false` sat between. Main's two `false` arms stand and the process's is a third. - tests/toyos-rust-tests/src/bin/process_lifecycle.rs, the imports: #642 deleted `toyos::AsHandle` with the pid arm, its one user; this branch's `toyos::poller` import stands alone. Everything else merged by itself: #642's deletions in kernel/src/object/process.rs beside this branch's `Arc<Watch>`, #659's init changes beside the one doc sentence this branch deletes, and the `rust` gitlink at main's 95960d6c214. This commit is the resolution and nothing else. What #655's contract changes in this branch's own lines is the next commit's. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_013UDZQ6fSKw14e4w2TKTRfm

Japabu and others added 2 commits September 30, 2026 19:10

Japabu marked this pull request as ready for review September 30, 2026 18:22

Japabu and others added 2 commits September 30, 2026 20:36

Merge remote-tracking branch 'origin/main' into wt/toyos-tonefix

1e958aa

Japabu changed the title ~~hda_tone: the tone job's stream is gone from soundd before the next job's opens, and the judge refuses a shared window~~ hda_tone: the judge refuses multi-stream sessions, and cpal's ToyOS Drop waits a bounded time for soundd's EOF Sep 30, 2026

Japabu changed the title ~~hda_tone: the judge refuses multi-stream sessions, and cpal's ToyOS Drop waits a bounded time for soundd's EOF~~ hda_tone: the judge refuses multi-stream sessions, and a dropped cpal stream waits a bounded time on soundd and then lets go Sep 30, 2026

Japabu added this pull request to the merge queue Sep 30, 2026

Merged via the queue into main with commit 649ea51 Sep 30, 2026
1 check passed

Japabu deleted the wt/toyos-tonefix branch September 30, 2026 20:21

Japabu mentioned this pull request Sep 30, 2026

Every QEMU ceiling is at most three times what its test takes; wedges end in seconds; two LAN boots ride the talking boot #638

Merged

Japabu mentioned this pull request Oct 1, 2026

The redlist and the recorded durations go: a red test is fixed or deleted with its issue, a flaky test is deleted at once, and shards deal the task list in turn #639

Merged

Japabu mentioned this pull request Oct 2, 2026

A child's end is readiness on its Process handle: OP_WATCH answers at the published exit, and no close ends another handle's watch #648

Merged

Navigation Menu

Repository navigation

hda_tone: the judge refuses multi-stream sessions, and a dropped cpal stream waits a bounded time on soundd and then lets go - #641

hda_tone: the judge refuses multi-stream sessions, and a dropped cpal stream waits a bounded time on soundd and then lets go#641
Japabu merged 5 commits into
mainfrom
wt/toyos-tonefix

Japabu commented Sep 30, 2026 •

edited

Loading

Uh oh!

Japabu commented Sep 30, 2026

Uh oh!

Japabu commented Sep 30, 2026

Uh oh!

Japabu commented Sep 30, 2026

Uh oh!

Japabu commented Sep 30, 2026

Uh oh!

Japabu commented Sep 30, 2026

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

Conversation

Japabu commented Sep 30, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Root cause

The fix

Measured on the T14 at 1621eb5

Gates

Unsure

Uh oh!

Japabu commented Sep 30, 2026

Uh oh!

Japabu commented Sep 30, 2026

Uh oh!

Japabu commented Sep 30, 2026

Uh oh!

Japabu commented Sep 30, 2026

Uh oh!

Japabu commented Sep 30, 2026

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

Japabu commented Sep 30, 2026 •

edited

Loading

Measured on the T14 at `1621eb5`