From 8b522da89ee2e5c6c90ca3e3bf9b66c3f9fc022d Mon Sep 17 00:00:00 2001 From: japabu Date: Wed, 30 Sep 2026 19:10:43 +0200 Subject: [PATCH 1/4] hda_tone's judge refuses a window another job's stream shared 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 Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L --- ...s-on-the-t14-where-its-judge-wants-none.md | 50 ------------------- tests/checks/audio.rs | 17 +++++++ tests/common/audio.rs | 19 ++++++- 3 files changed, 35 insertions(+), 51 deletions(-) delete mode 100644 issues/audio/hda-tone-reads-underruns-on-the-t14-where-its-judge-wants-none.md diff --git a/issues/audio/hda-tone-reads-underruns-on-the-t14-where-its-judge-wants-none.md b/issues/audio/hda-tone-reads-underruns-on-the-t14-where-its-judge-wants-none.md deleted file mode 100644 index 662d835b131..00000000000 --- a/issues/audio/hda-tone-reads-underruns-on-the-t14-where-its-judge-wants-none.md +++ /dev/null @@ -1,50 +0,0 @@ ---- -status: open -kind: defect -opened: 2026-09-29 ---- - -# `hda_tone` reads underruns on the T14 where its judge wants none - -The T14 run of `wt/toyos-metaljudges` at `f5c80264f` reds the row with: - -``` -FAIL hda_tone: soundd filled 104 period(s) the tone client had not covered, on a client that keeps its ring full: -``` - -The job itself exits 0 and prints `tone done`. Its cause is not measured; -whether the judge or soundd is wrong is open. - -The T14 run of `main` at `7e151819` reddened the row earlier, on `the -testcases's log carried no kernel output at all`. - -## Measured - -The `testcases` boot's log over the window the judge printed, selected lines in -order: - -``` -{… 3.021 tid=1 soundd} soundd: opening stream: 44100Hz 2ch fmt=0 -{… 3.021 soundd} soundd: client 0 connected (id=0) -{… 3.021 soundd} soundd: resumed -{… 5.024 soundd} soundd: wakes=984 completions=689 submitted=697 underruns=0 drains=0 … clients=1 … -[… 6.252 cpu0 tid=1] exit: test_rs_audio_tone tid=1 code=0 cpu=12ms (after 48 like it suppressed) -{… 6.252 pid=8 test-runner} tone done -{… 6.252 test-runner} ===TEST_END test_rs_audio_tone exit=0=== -{… 6.252 test-runner} ===TEST_START test_rs_hda_client_stall=== -[… 6.253 cpu7] spawn: /system/bin/test_rs_hda_client_stall pid=9 … -{… 6.254 tid=1 soundd} soundd: opening stream: 44100Hz 2ch fmt=0 -{… 6.254 soundd} soundd: client 1 connected (id=1) -{… 6.258 soundd} soundd: client 0 removed (closed) -{… 7.024 soundd} soundd: wakes=989 completions=688 submitted=688 underruns=39 drains=0 … clients=1 … -{… 8.412 soundd} soundd: client 1 removed (closed) -{… 8.418 soundd} soundd: wakes=741 completions=479 submitted=479 underruns=65 drains=0 … clients=0 … -``` - -The printed window carries three stats lines, with `underruns=0`, `underruns=39` -and `underruns=65`, which sum to the 104 the row names. - -## Exit condition - -`hda_tone` PASS on the orchestrator's T14 run of the head that lands the fix, -and this file is deleted. diff --git a/tests/checks/audio.rs b/tests/checks/audio.rs index 2bfc573c6f7..25344dff0c1 100644 --- a/tests/checks/audio.rs +++ b/tests/checks/audio.rs @@ -48,6 +48,23 @@ pub fn judges_verdict() -> Result<(), String> { &format!("{}{{0.600 soundd}} {NULL_SINK}\n{next}", tone(stats(0, 0, 0))), false, )?; + // The next job's stream connected before soundd let the tone's go, so the + // tone's last window is both streams' whatever it counted. + judged( + "a tone another job's stream joined", + tone_on_metal, + &format!( + "{configured}{}{{1.000 soundd}} soundd: client 0 connected (id=1)\n{}{next}\ + {{3.000 soundd}} soundd: client 1 connected (id=2)\n\ + {{3.000 soundd}} soundd: client 1 removed (closed)\n{}\ + {{4.000 soundd}} soundd: client 2 removed (closed)\n{}", + spawn("test_rs_audio_tone"), + stats(0, 1, 0), + stats(0, 1, 0), + stats(0, 0, 0), + ), + false, + )?; let stall = |second: String, rest: &str| { format!( diff --git a/tests/common/audio.rs b/tests/common/audio.rs index 5c3f9601bf8..29332580ed1 100644 --- a/tests/common/audio.rs +++ b/tests/common/audio.rs @@ -10,6 +10,11 @@ use super::serial::Serial; /// that carries `clients=0`, which soundd writes after the removal — and not at /// the next job's spawn, which can land before it. A job that plays nothing /// (`sessions` of 0) ends at the next test binary's spawn. +/// +/// Sessions are refused unless each is one stream: soundd counts one window +/// across every client it holds, so a session another job's stream shared has +/// no count that is the job's alone. What keeps jobs apart is cpal's ToyOS +/// host, whose `Drop` returns only once soundd has let the stream go. fn job_window<'a>(log: &'a str, job: &str, sessions: usize) -> Result<&'a str, String> { let head = format!("spawn: /system/bin/{job} "); let at = log.find(&head).ok_or_else(|| format!("no `{head}` record: {job} never ran"))?; @@ -32,7 +37,19 @@ fn job_window<'a>(log: &'a str, job: &str, sessions: usize) -> Result<&'a str, S })?; end = rest[flushed..].find('\n').map_or(rest.len(), |nl| flushed + nl + 1); } - Ok(&rest[..end]) + let window = &rest[..end]; + let streams = window + .lines() + .filter(|l| l.contains("soundd: client ") && l.contains(" connected (id=")) + .count(); + if streams != sessions { + return Err(format!( + "soundd connected {streams} stream(s) in {job}'s {sessions} session(s): another \ + job's stream shared soundd with {job}'s, and no count in the window is {job}'s \ + alone:\n{window}" + )); + } + Ok(window) } /// What soundd's flush on its last client leaving carries, and no other stats From 1621eb5f0628b5c68e900f71f51d93073a35b09b Mon Sep 17 00:00:00 2001 From: japabu Date: Wed, 30 Sep 2026 19:10:43 +0200 Subject: [PATCH 2/4] A job's audio stream is gone from soundd before the job is 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 f5c80264f, 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 Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L --- tests/toyos-rust-tests/Cargo.lock | 2 +- userland/Cargo.lock | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/tests/toyos-rust-tests/Cargo.lock b/tests/toyos-rust-tests/Cargo.lock index 5879429cd2b..54508a7d126 100644 --- a/tests/toyos-rust-tests/Cargo.lock +++ b/tests/toyos-rust-tests/Cargo.lock @@ -337,7 +337,7 @@ dependencies = [ [[package]] name = "cpal" version = "0.18.0" -source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#7e9775d5dc50b0da933fb947c806bd420ff6e85d" +source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#18f2db21c709234f80dffff0cb813a7dda4a7dc4" dependencies = [ "alsa", "block2 0.6.2", diff --git a/userland/Cargo.lock b/userland/Cargo.lock index 600a2d3b028..c16e5cbba98 100644 --- a/userland/Cargo.lock +++ b/userland/Cargo.lock @@ -605,7 +605,7 @@ dependencies = [ [[package]] name = "cpal" version = "0.18.0" -source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#7e9775d5dc50b0da933fb947c806bd420ff6e85d" +source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#18f2db21c709234f80dffff0cb813a7dda4a7dc4" dependencies = [ "alsa", "block2 0.6.2", From dfc9da078a5f8628d78103a6d40acf69f4714478 Mon Sep 17 00:00:00 2001 From: japabu Date: Wed, 30 Sep 2026 21:00:03 +0200 Subject: [PATCH 3/4] A dropped cpal stream waits on soundd for a bounded time 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 Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L --- ...-deadline-mirrors-soundds-fade-and-ring.md | 25 ++++ ...ds-one-resume-where-its-judge-wants-two.md | 35 +++++- tests/checks/audio.rs | 27 +++++ tests/common/audio.rs | 21 ++-- tests/toyos-rust-tests/Cargo.lock | 2 +- .../src/bin/cpal_drop_unreleased.rs | 114 ++++++++++++++++++ userland/Cargo.lock | 2 +- 7 files changed, 213 insertions(+), 13 deletions(-) create mode 100644 issues/audio/cpal-drop-deadline-mirrors-soundds-fade-and-ring.md create mode 100644 tests/toyos-rust-tests/src/bin/cpal_drop_unreleased.rs diff --git a/issues/audio/cpal-drop-deadline-mirrors-soundds-fade-and-ring.md b/issues/audio/cpal-drop-deadline-mirrors-soundds-fade-and-ring.md new file mode 100644 index 00000000000..434ee1098dd --- /dev/null +++ b/issues/audio/cpal-drop-deadline-mirrors-soundds-fade-and-ring.md @@ -0,0 +1,25 @@ +--- +status: open +kind: defect +opened: 2026-09-30 +--- + +# cpal's ToyOS `Drop` bounds its wait on soundd with two numbers soundd never sent + +A dropped cpal `Stream` waits for soundd to close its signal pipe for at most +soundd's 5 ms fade, in whole periods, plus the 8 periods of the stream's ring: +1280 frames at 44100 Hz (ToyOSOrg/cpal `toyos-0.18.0`, `src/host/toyos/mod.rs`, +`RELEASE_WITHIN`). Past it, `Drop` refuses by name and returns. + +The period and the rate are soundd's answer to the open, and the host asserts +them. The fade (`toyos_mixer::ramp_frames`) and the ring depth (soundd's +`slot_count`, see `client-ring-depth-is-the-devices-pipeline-depth.md`) are +copies: `StreamOpenResponse` carries `slot_count` and `AudioStream` keeps it to +itself, and nothing carries the fade. If soundd's fade grows or a device's +pipeline deepens, the bound shrinks under what soundd needs, and a healthy +soundd is refused. + +## Exit condition + +`AudioStream` says the stream's ring depth and soundd's fade, the cpal host +derives `RELEASE_WITHIN` from them, and this file is deleted. diff --git a/issues/audio/hda-client-stall-reads-one-resume-where-its-judge-wants-two.md b/issues/audio/hda-client-stall-reads-one-resume-where-its-judge-wants-two.md index 01804c4d582..61070a4c295 100644 --- a/issues/audio/hda-client-stall-reads-one-resume-where-its-judge-wants-two.md +++ b/issues/audio/hda-client-stall-reads-one-resume-where-its-judge-wants-two.md @@ -13,7 +13,6 @@ FAIL hda_client_stall: soundd resumed 0 time(s) — the second stream did not fi ``` The job itself exits 0 and prints `stalled 8 then 2 times, soundd survived`. -Its cause is not measured; whether the judge or soundd is wrong is open. ## Measured @@ -44,6 +43,40 @@ The `testcases` boot's log, from the job's spawn to its end, in order: the previous client's removal at `6.275` and its open at `6.333`, so `client_stall_on_metal`'s `resumes < 2` reds on that span too. +## Measured once a job's stream is gone before the job exits + +The `testcases` boot of the orchestrator's T14 `--metal hda_tone` run at +`1621eb5f0` (#641), from the tone's removal to the stall's end, in order: + +``` +{… 5.670 soundd} soundd: client 0 removed (closed) +{… 5.670 soundd} soundd: wakes=645 … clients=0 … +[… 5.670 cpu4] exit: test_rs_audio_tone pid=11 code=0 cpu=2ms +[… 5.672 cpu7] spawn: /system/bin/test_rs_hda_client_stall pid=12 … +{… 5.673 tid=1 soundd} soundd: opening stream: 44100Hz 2ch fmt=0 +{… 5.673 soundd} soundd: client 0 connected (id=1) +{… 7.830 soundd} soundd: client 1 removed (closed) +{… 7.830 soundd} soundd: wakes=79 … clients=0 … +{… 7.854 soundd} soundd: suspended +{… 8.130 tid=1 soundd} soundd: opening stream: 44100Hz 2ch fmt=0 +{… 8.131 soundd} soundd: client 0 connected (id=2) +{… 8.131 soundd} soundd: resumed +{… 9.040 soundd} soundd: client 2 removed (closed) +{… 9.040 soundd} soundd: wakes=465 … clients=0 … +{… 9.063 soundd} soundd: suspended +``` + +- The tone's stream is removed, and its session flushed, before its job + exits; the stall's first stream opens 3 ms after that exit. +- soundd suspends 20 to 25 ms after the last removal: `7.830`→`7.854` and + `9.040`→`9.063` here, `8.565`→`8.585` and `9.755`→`9.780` above. +- So the first stream opens on a soundd that has not suspended, which is not + the premise `client_stall_on_metal` asks of it. The judge reads this log as: + +``` +FAIL hda_client_stall: soundd resumed 1 time(s) — the second stream did not find a suspended daemon, so nothing here tests a resume: +``` + ## Exit condition `hda_client_stall` PASS on the orchestrator's T14 run of the head that lands diff --git a/tests/checks/audio.rs b/tests/checks/audio.rs index 25344dff0c1..df340713435 100644 --- a/tests/checks/audio.rs +++ b/tests/checks/audio.rs @@ -65,6 +65,33 @@ pub fn judges_verdict() -> Result<(), String> { ), false, )?; + 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, + )?; + // Another job's stream, held since before the spawn, is still held when the + // tone's connects: one connect in the window, and two removals. + judged( + "a tone beside a stream soundd held at its spawn", + tone_on_metal, + &format!( + "{configured}{{0.900 soundd}} soundd: client 0 connected (id=0)\n{}\ + {{1.000 soundd}} soundd: client 1 connected (id=1)\n{}\ + {{2.500 soundd}} soundd: client 0 removed (closed)\n\ + {{3.000 soundd}} soundd: client 1 removed (closed)\n{}{next}", + spawn("test_rs_audio_tone"), + stats(0, 2, 0), + stats(0, 0, 0), + ), + false, + )?; let stall = |second: String, rest: &str| { format!( diff --git a/tests/common/audio.rs b/tests/common/audio.rs index 29332580ed1..ec089233663 100644 --- a/tests/common/audio.rs +++ b/tests/common/audio.rs @@ -13,8 +13,7 @@ use super::serial::Serial; /// /// Sessions are refused unless each is one stream: soundd counts one window /// across every client it holds, so a session another job's stream shared has -/// no count that is the job's alone. What keeps jobs apart is cpal's ToyOS -/// host, whose `Drop` returns only once soundd has let the stream go. +/// no count that is the job's alone. fn job_window<'a>(log: &'a str, job: &str, sessions: usize) -> Result<&'a str, String> { let head = format!("spawn: /system/bin/{job} "); let at = log.find(&head).ok_or_else(|| format!("no `{head}` record: {job} never ran"))?; @@ -38,15 +37,17 @@ fn job_window<'a>(log: &'a str, job: &str, sessions: usize) -> Result<&'a str, S end = rest[flushed..].find('\n').map_or(rest.len(), |nl| flushed + nl + 1); } let window = &rest[..end]; - let streams = window - .lines() - .filter(|l| l.contains("soundd: client ") && l.contains(" connected (id=")) - .count(); - if streams != sessions { + let said = |what: &str| { + window.lines().filter(|l| l.contains("soundd: client ") && l.contains(what)).count() + }; + // A removal counts too: a stream soundd held before the spawn connected + // outside the window and leaves inside it. + let (streams, removed) = (said(" connected (id="), said(" removed (")); + if streams != sessions || removed != sessions { return Err(format!( - "soundd connected {streams} stream(s) in {job}'s {sessions} session(s): another \ - job's stream shared soundd with {job}'s, and no count in the window is {job}'s \ - alone:\n{window}" + "soundd connected {streams} and removed {removed} stream(s) in {job}'s {sessions} \ + session(s): another job's stream shared soundd with {job}'s, and no count in the \ + window is {job}'s alone:\n{window}" )); } Ok(window) diff --git a/tests/toyos-rust-tests/Cargo.lock b/tests/toyos-rust-tests/Cargo.lock index 54508a7d126..b9dda6d9061 100644 --- a/tests/toyos-rust-tests/Cargo.lock +++ b/tests/toyos-rust-tests/Cargo.lock @@ -337,7 +337,7 @@ dependencies = [ [[package]] name = "cpal" version = "0.18.0" -source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#18f2db21c709234f80dffff0cb813a7dda4a7dc4" +source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#061f134fa11418dbe0afc546e10d8b0dc9f9752f" dependencies = [ "alsa", "block2 0.6.2", diff --git a/tests/toyos-rust-tests/src/bin/cpal_drop_unreleased.rs b/tests/toyos-rust-tests/src/bin/cpal_drop_unreleased.rs new file mode 100644 index 00000000000..0c327730393 --- /dev/null +++ b/tests/toyos-rust-tests/src/bin/cpal_drop_unreleased.rs @@ -0,0 +1,114 @@ +//! cpal's ToyOS host, dropped while its stream's server never lets go of it. +//! +//! This binary is the stream's server: it answers the open as soundd does, and +//! then holds the signal pipe open and never writes it — a soundd whose mix +//! loop has stopped. Its child, the same binary with `client`, reaches it as +//! `soundd`, builds a stream through cpal and drops it unplayed. The stream +//! thread sends the close and waits on the pipe; `Drop` has to come back with +//! the refusal by name through the error callback rather than wait for good. +//! +//! No sound is played and soundd is not involved. + +use std::os::toyos::process::CommandExt; +use std::process::Command; +use std::sync::mpsc; + +use cpal::traits::{DeviceTrait, HostTrait}; +use toyos::audio::{ + StreamOpenRequest, StreamOpenResponse, MSG_STREAM_CLOSE, MSG_STREAM_OPEN, MSG_STREAM_OPENED, +}; +use toyos::shm::SharedMemory; +use toyos::{namespace, port}; +use toyos_abi::audio::AudioSlotHeader; +use toyos_abi::syscall::SVC_LABEL; + +const SELF: &str = "/system/bin/test_rs_cpal_drop_unreleased"; + +/// cpal's ToyOS host's words for a soundd that did not let go. +const REFUSAL: &str = "soundd did not let go of the closed stream within "; + +/// What soundd answers a 44100 Hz stereo open with, which is the one stream +/// cpal's ToyOS host opens. +const OPENED: StreamOpenResponse = StreamOpenResponse { + client_period_frames: 128, + client_period_bytes: 512, + device_sample_rate: 44_100, + device_channels: 2, + slot_count: 8, +}; + +fn main() { + match std::env::args().nth(1).as_deref() { + None => serve(), + Some("client") => client(), + Some(other) => panic!("no role {other:?}"), + } +} + +fn serve() { + let (acceptor, connector) = port::create().expect("a port"); + let names = namespace::build() + .add("soundd", &connector) + .finish() + .expect("a namespace naming this binary soundd"); + let mut child = Command::new(SELF) + .arg("client") + .endow(SVC_LABEL, names.into_raw().0) + .spawn() + .expect("spawn the client"); + + let conn = acceptor.accept().expect("the client's connection"); + let (kind, _): (u32, StreamOpenRequest) = conn.recv().expect("the client's open"); + assert_eq!(kind, MSG_STREAM_OPEN, "the client's first frame is not an open"); + let ring = SharedMemory::create( + AudioSlotHeader::SIZE + OPENED.slot_count as usize * OPENED.client_period_bytes as usize, + ) + .expect("a ring"); + let (signal_read, signal_write) = toyos::pipe_pair().expect("a signal pipe"); + conn.send_with_handles( + &[ring.share().expect("the ring to share"), signal_read.into_raw()], + MSG_STREAM_OPENED, + &OPENED, + ) + .expect("the open answered"); + + let close = conn.recv_header().expect("the client's close"); + assert_eq!(close.msg_type, MSG_STREAM_CLOSE, "the dropped stream did not close"); + + // The write end is held until the client has gone, so nothing but its + // own deadline can end its wait. + let status = child.wait().expect("wait for the client"); + drop(signal_write); + assert!(status.success(), "the client exited {status:?}"); + println!("cpal's drop came back while its server held the signal pipe"); +} + +fn client() { + let device = cpal::default_host() + .default_output_device() + .expect("the ToyOS host's output"); + let config = device.default_output_config().expect("its config"); + let (said, heard) = mpsc::channel(); + let stream = device + .build_output_stream( + config.into(), + |_: &mut [i16], _: &cpal::OutputCallbackInfo| { + unreachable!("a stream never played is never asked for audio") + }, + move |error: cpal::Error| said.send(error).expect("main hears every error"), + None, + ) + .expect("the open answered"); + drop(stream); + + let errors: Vec = heard.try_iter().collect(); + assert!( + matches!( + errors.as_slice(), + [refused] if refused.kind() == cpal::ErrorKind::HostUnavailable + && refused.to_string().starts_with(REFUSAL) + ), + "the drop came back with {errors:?}, not the refusal" + ); + println!("client: {}", errors[0]); +} diff --git a/userland/Cargo.lock b/userland/Cargo.lock index c16e5cbba98..e9679af4ce9 100644 --- a/userland/Cargo.lock +++ b/userland/Cargo.lock @@ -605,7 +605,7 @@ dependencies = [ [[package]] name = "cpal" version = "0.18.0" -source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#18f2db21c709234f80dffff0cb813a7dda4a7dc4" +source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#061f134fa11418dbe0afc546e10d8b0dc9f9752f" dependencies = [ "alsa", "block2 0.6.2", From 597d60a4e238b7c74633834d3e66f4bbd8b89735 Mon Sep 17 00:00:00 2001 From: japabu Date: Wed, 30 Sep 2026 21:49:17 +0200 Subject: [PATCH 4/4] A dropped cpal stream soundd has not let go of ends at its refusal 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 Claude-Session: https://claude.ai/code/session_016t9wjdQkB8SH7bmfUoiy6L --- .../cpal-backend-hardcodes-the-format.md | 13 +++++ ...-deadline-mirrors-soundds-fade-and-ring.md | 25 ---------- tests/toyos-rust-tests/Cargo.lock | 2 +- .../src/bin/cpal_drop_unreleased.rs | 48 +++++++++++++++---- tests/toyos-rust-tests/src/tone.rs | 10 +++- userland/Cargo.lock | 2 +- 6 files changed, 64 insertions(+), 36 deletions(-) delete mode 100644 issues/audio/cpal-drop-deadline-mirrors-soundds-fade-and-ring.md diff --git a/issues/audio/cpal-backend-hardcodes-the-format.md b/issues/audio/cpal-backend-hardcodes-the-format.md index 3b27aba0842..7b341a81daf 100644 --- a/issues/audio/cpal-backend-hardcodes-the-format.md +++ b/issues/audio/cpal-backend-hardcodes-the-format.md @@ -11,6 +11,19 @@ client and therefore effectively untested. The backend also `assert_eq!`s the device rate against a compile-time constant, so changing the driver's rate aborts every cpal app. +**`Drop`'s bound on soundd is built from copies the same way.** A dropped +`Stream` waits for soundd to close its signal pipe for at most soundd's 5 ms +fade, in whole periods, plus the 8 periods of the stream's ring: 1280 frames at +44100 Hz (`RELEASE_WITHIN`). Past it, `Drop` refuses by name and returns. The +fade (`toyos_mixer::ramp_frames`) and the ring depth (soundd's `slot_count`, see +`issues/audio/client-ring-depth-is-the-devices-pipeline-depth.md`) are copies: +`StreamOpenResponse.slot_count` reaches `AudioStream::open` and stays private, +and no message carries the fade. If soundd's fade grows or a device's pipeline +deepens, the bound shrinks under what soundd needs, and a healthy soundd is +refused. That part goes when `AudioStream` says the ring depth and the fade and +the host derives `RELEASE_WITHIN` from them, which changes `toyos/src` and the +audio protocol. + Deferred to the quiet-tree window, not neglected: editing that fork needs `.cargo/config.toml` path overrides, which redirect cpal for **every** agent in the tree. Same scheduling constraint as the fork lint audit. diff --git a/issues/audio/cpal-drop-deadline-mirrors-soundds-fade-and-ring.md b/issues/audio/cpal-drop-deadline-mirrors-soundds-fade-and-ring.md deleted file mode 100644 index 434ee1098dd..00000000000 --- a/issues/audio/cpal-drop-deadline-mirrors-soundds-fade-and-ring.md +++ /dev/null @@ -1,25 +0,0 @@ ---- -status: open -kind: defect -opened: 2026-09-30 ---- - -# cpal's ToyOS `Drop` bounds its wait on soundd with two numbers soundd never sent - -A dropped cpal `Stream` waits for soundd to close its signal pipe for at most -soundd's 5 ms fade, in whole periods, plus the 8 periods of the stream's ring: -1280 frames at 44100 Hz (ToyOSOrg/cpal `toyos-0.18.0`, `src/host/toyos/mod.rs`, -`RELEASE_WITHIN`). Past it, `Drop` refuses by name and returns. - -The period and the rate are soundd's answer to the open, and the host asserts -them. The fade (`toyos_mixer::ramp_frames`) and the ring depth (soundd's -`slot_count`, see `client-ring-depth-is-the-devices-pipeline-depth.md`) are -copies: `StreamOpenResponse` carries `slot_count` and `AudioStream` keeps it to -itself, and nothing carries the fade. If soundd's fade grows or a device's -pipeline deepens, the bound shrinks under what soundd needs, and a healthy -soundd is refused. - -## Exit condition - -`AudioStream` says the stream's ring depth and soundd's fade, the cpal host -derives `RELEASE_WITHIN` from them, and this file is deleted. diff --git a/tests/toyos-rust-tests/Cargo.lock b/tests/toyos-rust-tests/Cargo.lock index b9dda6d9061..a7acd1875f0 100644 --- a/tests/toyos-rust-tests/Cargo.lock +++ b/tests/toyos-rust-tests/Cargo.lock @@ -337,7 +337,7 @@ dependencies = [ [[package]] name = "cpal" version = "0.18.0" -source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#061f134fa11418dbe0afc546e10d8b0dc9f9752f" +source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#29180f7b5a524e6709d30c010e7e0280cd82ccda" dependencies = [ "alsa", "block2 0.6.2", diff --git a/tests/toyos-rust-tests/src/bin/cpal_drop_unreleased.rs b/tests/toyos-rust-tests/src/bin/cpal_drop_unreleased.rs index 0c327730393..092814e2d0c 100644 --- a/tests/toyos-rust-tests/src/bin/cpal_drop_unreleased.rs +++ b/tests/toyos-rust-tests/src/bin/cpal_drop_unreleased.rs @@ -1,22 +1,27 @@ //! cpal's ToyOS host, dropped while its stream's server never lets go of it. //! //! This binary is the stream's server: it answers the open as soundd does, and -//! then holds the signal pipe open and never writes it — a soundd whose mix -//! loop has stopped. Its child, the same binary with `client`, reaches it as -//! `soundd`, builds a stream through cpal and drops it unplayed. The stream -//! thread sends the close and waits on the pipe; `Drop` has to come back with -//! the refusal by name through the error callback rather than wait for good. +//! then holds the signal pipe open without writing it until the client's +//! `Drop` has come back — a soundd whose mix loop has stopped. Its child, the +//! same binary with `client`, reaches it as `soundd`, builds a stream through +//! cpal and drops it unplayed. The stream thread sends the close and waits on +//! the pipe; `Drop` has to come back with the refusal by name through the error +//! callback rather than wait for good. One signal then has to end the stream +//! thread while its process lives, so the stream's connection closes as it +//! would for soundd. //! //! No sound is played and soundd is not involved. +use std::io::{BufRead, BufReader, Read}; use std::os::toyos::process::CommandExt; -use std::process::Command; +use std::process::{Command, Stdio}; use std::sync::mpsc; use cpal::traits::{DeviceTrait, HostTrait}; use toyos::audio::{ StreamOpenRequest, StreamOpenResponse, MSG_STREAM_CLOSE, MSG_STREAM_OPEN, MSG_STREAM_OPENED, }; +use toyos::ipc::IpcError; use toyos::shm::SharedMemory; use toyos::{namespace, port}; use toyos_abi::audio::AudioSlotHeader; @@ -54,6 +59,8 @@ fn serve() { let mut child = Command::new(SELF) .arg("client") .endow(SVC_LABEL, names.into_raw().0) + .stdin(Stdio::piped()) + .stdout(Stdio::piped()) .spawn() .expect("spawn the client"); @@ -76,11 +83,33 @@ fn serve() { assert_eq!(close.msg_type, MSG_STREAM_CLOSE, "the dropped stream did not close"); // The write end is held until the client has gone, so nothing but its - // own deadline can end its wait. + // own deadline can end its wait. The client says the refusal once `Drop` + // has returned with it. + let mut said = String::new(); + BufReader::new(child.stdout.take().expect("the client's stdout")) + .read_line(&mut said) + .expect("the client's line"); + assert!(said.starts_with("client: "), "the client said {said:?} before its drop came back"); + print!("{said}"); + + signal_write.write(&[1]).expect("a signal to the stream thread"); + match conn.recv_header() { + Err(IpcError::Disconnected) => {} + other => panic!( + "the stream's connection gave {:?} after its close, not its end", + other.map(|h| h.msg_type) + ), + } + // The client exits once its stdin closes, so the connection's end above + // was the stream thread's. + drop(child.stdin.take()); let status = child.wait().expect("wait for the client"); drop(signal_write); assert!(status.success(), "the client exited {status:?}"); - println!("cpal's drop came back while its server held the signal pipe"); + println!( + "cpal's drop came back while its server held the signal pipe, and the next signal \ + ended its stream thread" + ); } fn client() { @@ -111,4 +140,7 @@ fn client() { "the drop came back with {errors:?}, not the refusal" ); println!("client: {}", errors[0]); + + let mut rest = Vec::new(); + std::io::stdin().read_to_end(&mut rest).expect("the server's end of stdin"); } diff --git a/tests/toyos-rust-tests/src/tone.rs b/tests/toyos-rust-tests/src/tone.rs index 72e0e5f7e38..12088219b80 100644 --- a/tests/toyos-rust-tests/src/tone.rs +++ b/tests/toyos-rust-tests/src/tone.rs @@ -27,6 +27,8 @@ pub fn play_tone() { let done = Arc::new(AtomicBool::new(false)); let done2 = done.clone(); let position = Arc::new(AtomicU64::new(0)); + let failed = Arc::new(AtomicBool::new(false)); + let failed2 = failed.clone(); let stream = device .build_output_stream( @@ -48,7 +50,10 @@ pub fn play_tone() { done2.store(true, Ordering::Relaxed); } }, - |err| eprintln!("audio error: {err}"), + move |err| { + eprintln!("audio error: {err}"); + failed2.store(true, Ordering::Relaxed); + }, None, ) .expect("failed to build audio stream"); @@ -61,4 +66,7 @@ pub fn play_tone() { // Let the tail of the tone drain through soundd and the device. std::thread::sleep(std::time::Duration::from_millis(200)); + + drop(stream); + assert!(!failed.load(Ordering::Relaxed), "the tone's stream reported an error, printed above"); } diff --git a/userland/Cargo.lock b/userland/Cargo.lock index e9679af4ce9..5489d455e17 100644 --- a/userland/Cargo.lock +++ b/userland/Cargo.lock @@ -605,7 +605,7 @@ dependencies = [ [[package]] name = "cpal" version = "0.18.0" -source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#061f134fa11418dbe0afc546e10d8b0dc9f9752f" +source = "git+https://github.com/ToyOSOrg/cpal?branch=toyos-0.18.0#29180f7b5a524e6709d30c010e7e0280cd82ccda" dependencies = [ "alsa", "block2 0.6.2",