diff --git a/CHANGELOG.md b/CHANGELOG.md index 0fae8cf01..eaff89050 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -53,6 +53,12 @@ hashes are given where a change is easiest to understand by reading the commit. - `[audio] file = "out.wav"` plays every machine's sound into a WAV file in real time instead of a sound card. +- The monitor's `audio status` reports every audio card (HAL2, MACE audio, RAD1 + on the Octane and Onyx2, the Tezro's ICE1724) in one layout: per output the + frames moved and the guest rate, host underruns, frames the host dropped and + where the output goes. Underruns now count only while an output runs. It + replaces `hal2 status`. + ### Every machine has a built-in PROM - The O2, Octane, Origin 200, Origin 2000, Onyx2, Fuel, Tezro, Origin 3200 and diff --git a/clanker/perf/hal2-pump-thread.md b/clanker/perf/hal2-pump-thread.md index 606f9cea8..ffd990945 100644 --- a/clanker/perf/hal2-pump-thread.md +++ b/clanker/perf/hal2-pump-thread.md @@ -45,7 +45,7 @@ chasing unrelated kernel panics. ## Verify after HAL2 changes -- Telnet monitor `hal2 status` — `cpal underruns (samples)` should stay low +- Telnet monitor `audio status` — `host underruns` should stay low during desktop idle and under `glxgears`-style load. - **Boot a fresh IRIX image and confirm the startup chime plays correctly** (not silent, not garbled/truncated) — this was the concrete symptom that diff --git a/debug.md b/debug.md index 9c31aa1cf..226c84681 100644 --- a/debug.md +++ b/debug.md @@ -568,8 +568,7 @@ to learn the cursor's hotspot exactly. | `rtc r ` / `rtc w ` | Read / write NVRAM bytes | | `rtc debug ` | RTC trace **[DEV]** | | `pit status` / `pit debug ` | 8254 timer state / trace **[DEV]** | -| `hal2 status` | HAL2 audio state | -| `ice1724 status` | The Tezro's ICE1724 audio controller (`[tezro] audio`): frames each engine moved, converter writes, accesses nothing establishes | +| `audio status` / `audio` | The machine's audio card (HAL2, MACE audio, RAD1, the Tezro's ICE1724), one layout on every card: for each output (`analog in`, `analog out`, `S/PDIF out`) the frames it has moved since the machine started and its guest rate (`off` while idle), the frames the host stream played as silence while the card was playing (underruns), the frames the host ring refused, and the host output (device and API, `file out.wav` or `none (no_audio)`). Counts are as of the card's last timer pass and are this run's, not saved in snapshots. HAL2 counts the frames its DMA channel supplies; MACE audio keeps its DAC clock running while the guest holds the device, so its moved count follows time, not sound. An Indy or Indigo2 with `no_audio` has no HAL2 and says so | | `ps2 status` / `ps2 debug ` | PS/2 controller state / keyboard and mouse trace | | `ps2 type ` / `ps2 enter` / `ps2 esc` | Type text / press Enter / press Esc (Esc stops PROM autoboot). On the Origin 3200 and Onyx 3000 these, `ps2 key` and `ps2 mouse` go to the I-brick's USB keyboard and mouse, and `ps2 status` still shows the unused PS/2 side | | `ps2 key ` | Hold or release a modifier | @@ -675,7 +674,7 @@ its SCSI controllers answer to `scsi`/`cow` and `scsi1`/`cow1` as described unde | `mec status` | MACE Ethernet: rings, receive buffers, frame counts | | `sdma status` | MACE serial DMA | | `maceps2 status` / `maceps2 traffic` | PS/2 ports / recent bytes each way | -| `audio status` / `audio codec` | MACE audio rings and rates / AD1843 codec registers | +| `audio codec` | MACE audio's AD1843 codec registers (`audio status` is the common report above) | | `ust status` | MACE UST counter | | `rtc status` / `rtc dump` / `rtc r ` / `rtc w ` | DS1687 RTC | | `onewire status` | MACE identity register and the ID chip holding the MAC address | diff --git a/docs/perfetto.md b/docs/perfetto.md index f82f814fb..e4c9370d7 100644 --- a/docs/perfetto.md +++ b/docs/perfetto.md @@ -35,7 +35,7 @@ event that belongs to several categories is recorded when any of them is on. | `dma` | HPC3 PDMA channels, VDMA (also `gfx`), IMPACT host DMA (also `gfx`). | | `scsi` | WD33C93A commands, CDBs and chip interrupts. | | `net` | Ethernet frames sent, received, refused and filtered. | -| `audio` | HAL2 codec arm/disarm, codec A pacing, host underruns. | +| `audio` | HAL2 codec arm/disarm, codec A pacing, host underruns of every audio card. | | `gfx` | vblank, flips, guest busy-waits, FIFO-full stalls, FIFO level, REX3 present, IMPACT engine busy. | | `prim` | One REX3 GO and its CPU raster work per primitive: up to millions per second under a busy X server. Drop it (`all,-prim`) for long captures. | | `jit` | jitv2 compile requests, compiles, compile queue full. | @@ -77,7 +77,7 @@ host thread's name. | DMA | `VDMA` | MC graphics DMA: `mem -> gio`, `gio -> mem`, `fill` (arg: bytes). | | `WD33C93A` | thread | `wd cmd` (arg: command), nested `cdb` (arg: target << 8 \| opcode), `chip int` (arg: status). | | `seeq-enet` | thread | `tx frame`, `rx frame` (arg: length), `rx no buffer`, `rx filtered`. | -| Audio | `HAL2`, `hptimer` | Codec `arm`/`disarm`, `host underrun` (the host audio callback found the ring empty), and a `codec A pace` slice per pacing wake on the timer thread. On the Octane, `RAD` has a `status slot` per status DMA completion (arg: the slot) and `late completion` when the host held up the timer thread (arg: µs late); the `RAD status slots unread` counter is how many slots the driver has not consumed (it warns that its thread was held off when all but one are). | +| Audio | `HAL2`, `host audio`, `hptimer` | Codec `arm`/`disarm`, `host underrun` on the `host audio` track for every card (the host audio callback found the ring empty while the card was playing), and a `codec A pace` slice per pacing wake on the timer thread. On the Octane, `RAD` has a `status slot` per status DMA completion (arg: the slot) and `late completion` when the host held up the timer thread (arg: µs late); the `RAD status slots unread` counter is how many slots the driver has not consumed (it warns that its thread was held off when all but one are). | | Graphics | `REX3 display`, `REX3 busy wait`, `REX3 gfifo full`, `REX3 gfifo level` | `vblank`; `xmap mode write` (how IRIX swaps Newport buffers); the guest reading GFXBUSY from STATUS (waiting for idle); CPU stores retried on a full GFIFO; the FIFO level as STATUS reports it. `REX3-Processor` has `GO` and nested `raster` slices per CPU primitive (`prim`); the refresh thread has `present`, `framebuffer copy`, per-plane upload, `compose`, and `readback` work. | | Graphics | `GR2 display`, `GR2 busy wait`, `GR2 fifo full` | `vblank`; reads and stores the board answered with bus-busy. | | Graphics | `GBE display`, `RE ib full`, `RE ib level` | O2: `timing interrupt` and `shadow latched` on the display track; the interface buffer's level and stores that found it full. The `CRIME-RE` thread shows `CRIME RE busy`, and with the `prim` category `RE primitive` / `RE MTE` slices. | diff --git a/src/dev/hal2.rs b/src/dev/hal2.rs index 0edde2f9f..42f47acba 100644 --- a/src/dev/hal2.rs +++ b/src/dev/hal2.rs @@ -7,7 +7,7 @@ use std::io::Write; use crate::traits::{BusRead8, BusRead16, BusRead32, BusRead64, BUS_OK, BUS_ERR, Device, DmaClient}; use crate::config::{AudioConfig, AudioHost}; use crate::hptimer::{TimerManager, TimerId, TimerReturn}; -use crate::host_audio::{HostOut as AudioOut, Resampler}; +use crate::host_audio::{HostOut as AudioOut, Meter, Resampler}; // HAL2 Register Offsets (relative to 0x1FBD8000) pub const HAL2_ISR: u32 = 0x10; // Interrupt Status Register @@ -238,19 +238,11 @@ struct CodecAState { dry: u32, nonzero_seen: bool, timer_id: Option, - /// The DMA channel the armed timer reads, and what it has done since - /// it was armed: callbacks, frames read, reads that found no data. - armed_ch: Option, - calls: u64, - frames: u64, - dry_reads: u64, } impl CodecAState { fn new() -> Self { - Self { out: None, resampler: None, prebuffering: true, prebuf: Vec::new(), - dry: 0, nonzero_seen: false, timer_id: None, - armed_ch: None, calls: 0, frames: 0, dry_reads: 0 } + Self { out: None, resampler: None, prebuffering: true, prebuf: Vec::new(), dry: 0, nonzero_seen: false, timer_id: None } } fn reset_audio(&mut self) { // Keep `out` — stream stays open. Just reset codec-side state. @@ -259,12 +251,8 @@ impl CodecAState { self.prebuf.clear(); self.dry = 0; self.nonzero_seen = false; - self.armed_ch = None; - self.calls = 0; - self.frames = 0; - self.dry_reads = 0; if let Some(o) = &self.out { - o.playing.store(false, Ordering::Relaxed); + o.meter.stopped(); } } /// Push interleaved i16 stereo pairs through the resampler into the ring buffer. @@ -272,7 +260,7 @@ impl CodecAState { if let Some(rs) = &mut self.resampler { if let Some(o) = &mut self.out { for chunk in samples.chunks_exact(2) { - rs.push(chunk[0], chunk[1], &mut o.producer); + o.push(rs, chunk[0], chunk[1]); } } } @@ -299,9 +287,6 @@ struct Hal2State { isr: u16, iar: u16, idr: [u16; 4], - /// The last indirect accesses (IAR, then IDR0..3 as they stood), for - /// `hal2 status`. - iar_log: std::collections::VecDeque<(u16, [u16; 4])>, // Internal Registers // ctrl[0] = CTRL1 (IDR0), ctrl[1] = CTRL2 IDR0, ctrl[2] = CTRL2 IDR1 @@ -393,7 +378,7 @@ pub struct Hal2 { at_state: Arc>, ar_state: Arc>, // cpal output-callback underrun count (ring buffer empty when the host pulled samples). - underruns: Arc, + meter: Arc, // [audio]: which host to play through, and its buffer size. audio: AudioConfig, } @@ -406,8 +391,8 @@ fn prebuf_samples(rate: u32) -> usize { /// The host output, through the shared `host_audio` (ring sized for HAL2's /// prebuffer). -fn open_persistent_output(audio: &AudioConfig, underruns: Arc, playing: Arc) -> Option { - crate::host_audio::open_output(audio, underruns, playing, |rate| prebuf_samples(rate) * RING_BUF_MULTIPLIER, "HAL2", "IRIS_HAL2_CAPTURE") +fn open_persistent_output(audio: &AudioConfig, meter: Arc) -> Option { + crate::host_audio::open_output(audio, meter, |rate| prebuf_samples(rate) * RING_BUF_MULTIPLIER, "HAL2", "IRIS_HAL2_CAPTURE") } // ─── impl Hal2 ──────────────────────────────────────────────────────────────── @@ -424,7 +409,6 @@ impl Hal2 { isr: 0, iar: 0, idr: [0; 4], - iar_log: std::collections::VecDeque::new(), codeca_ctrl: [0; 3], codecb_ctrl: [0; 3], aestx_ctrl: [0; 3], @@ -446,15 +430,11 @@ impl Hal2 { cb_state: Arc::new(Mutex::new(CodecBState { timer_id: None })), at_state: Arc::new(Mutex::new(AesTxState { timer_id: None })), ar_state: Arc::new(Mutex::new(AesRxState { loopback: std::collections::VecDeque::new(), timer_id: None })), - underruns: Arc::new(AtomicU64::new(0)), + meter: Meter::new("HAL2", &["analog in", "analog out"]), audio, } } - pub fn underrun_count(&self) -> u64 { - self.underruns.load(Ordering::Relaxed) - } - pub fn set_timer_manager(&self, tm: Arc) { let _ = self.timer_manager.set(tm); } @@ -537,7 +517,7 @@ impl Hal2 { let ca_state = self.ca_state.clone(); let mut pacer = Pacer::new(pitch_rate); - self.ca_state.lock().armed_ch = Some(dma_ch); + let meter = self.meter.clone(); let id = tm.add_recurring(Instant::now() + PACE_PERIOD, PACE_PERIOD, (), move |_| { let mut due = pacer.due(); // Keep within READ_AHEAD_MS of the position the guest last polled @@ -557,16 +537,13 @@ impl Hal2 { crate::pf_scope!(crate::perfetto::events::HAL2_PACE, due); let (gain_l, gain_r) = state.lock().output_gains(); let mut st = ca_state.lock(); - st.calls += 1; // No audio output — still drain DMA so the kernel doesn't hang // waiting for PDMA_CTRL_ACT to clear. let stream_rate = match st.out.as_ref() { Some(o) => o.stream_rate, None => { - for _ in 0..due { - let _ = read_frame_from(&dma_client, mode); - } + drain_without_host(&dma_client, mode, due, &meter); return TimerReturn::Continue; } }; @@ -578,13 +555,12 @@ impl Hal2 { dlog_dev!(LogModule::Hal2, "HAL2: Codec A resampler {}Hz (pitch={}) → {}Hz", rate, pitch_rate, stream_rate); } + let mut got = 0; for _ in 0..due { let frame = read_frame_from(&dma_client, mode); - if frame.is_some() { st.frames += 1; } else { st.dry_reads += 1; } - let was_prebuffering = st.prebuffering; - match frame { Some((l, r)) => { + got += 1; st.dry = 0; if !st.nonzero_seen && (l != 0 || r != 0) { dlog_dev!(LogModule::Hal2, "HAL2: Codec A first non-zero: l={} r={}", l, r); @@ -609,6 +585,15 @@ impl Hal2 { } None => { st.dry += 1; + // The HPC3 channel has nothing to read when it is not + // active (its chain ended or DMA was disabled) or its + // buffer is unreadable: nothing reaches the codec, so + // the host's silence is not an underrun. + if st.dry == 1 { + if let Some(o) = &st.out { + o.meter.stopped(); + } + } if st.prebuffering && !st.prebuf.is_empty() && st.dry >= DRY_LIMIT { // Flush whatever we buffered so far rather than waiting forever. let samples = std::mem::take(&mut st.prebuf); @@ -620,15 +605,9 @@ impl Hal2 { } } - // Prebuffering just finished — real audio is now flowing into the ring, - // so the cpal callback can start treating an empty ring as a genuine underrun. - if was_prebuffering && !st.prebuffering { - if let Some(o) = &st.out { - o.playing.store(true, Ordering::Relaxed); - } - } } + meter.moved(1, got); TimerReturn::Continue }); @@ -669,9 +648,12 @@ impl Hal2 { let dma_client = self.dma_clients[dma_ch].clone(); let mut pacer = Pacer::new(rate); + let meter = self.meter.clone(); let id = tm.add_recurring(Instant::now() + PACE_PERIOD, PACE_PERIOD, (), move |_| { - for _ in 0..pacer.due() { + let due = pacer.due(); + meter.moved(0, due); + for _ in 0..due { let _ = dma_client.write(0, false); if mode == MODE_STEREO || mode == MODE_QUAD { let _ = dma_client.write(0, false); @@ -850,11 +832,6 @@ impl Hal2 { fn handle_iar_write(&self, val: u16) { let mut state = self.state.lock(); state.iar = val; - let idr = state.idr; - if state.iar_log.len() == 32 { - state.iar_log.pop_front(); - } - state.iar_log.push_back((val, idr)); let is_read = (val & IAR_ACCESS_READ) != 0; let typ = val & IAR_TYPE_MASK; @@ -1143,6 +1120,18 @@ impl Hal2 { // ─── DMA read helper (free function to avoid borrow issues in closures) ─────── +/// With no host output, still read what the channel has so the guest's DMA +/// completes, and count it: the card is playing while the channel has frames. +fn drain_without_host(client: &Arc, mode: usize, due: u64, meter: &Meter) { + let got = (0..due).filter(|_| read_frame_from(client, mode).is_some()).count() as u64; + meter.moved(1, got); + if got > 0 { + meter.started(); + } else { + meter.stopped(); + } +} + fn read_frame_from(client: &Arc, mode: usize) -> Option<(i16, i16)> { if mode == MODE_MONO { let (v, st) = client.read()?; @@ -1178,7 +1167,7 @@ impl Device for Hal2 { fn start(&self) { // Open persistent audio output once. Codec A timer will push into it. - let audio = open_persistent_output(&self.audio, self.underruns.clone(), Arc::new(AtomicBool::new(false))); + let audio = open_persistent_output(&self.audio, self.meter.clone()); if audio.is_none() { eprintln!("HAL2: no audio output available"); } @@ -1201,102 +1190,17 @@ impl Device for Hal2 { fn get_clock(&self) -> u64 { 0 } - fn register_commands(&self) -> Vec<(String, String)> { - vec![("hal2".to_string(), "HAL2 commands: hal2 status".to_string())] - } - - fn execute_command(&self, cmd: &str, args: &[&str], mut writer: Box) -> Result<(), String> { - if cmd != "hal2" { return Err("Command not found".to_string()); } - - match args.first().map(|s| *s) { - Some("status") => { - let s = self.state.lock(); - - writeln!(writer, "ISR: 0x{:04x} global_reset_n={} codec_reset_n={} codec_mode={}", - s.isr, - (s.isr & isr::GLOBAL_RESET_N as u16 != 0) as u8, - (s.isr & isr::CODEC_RESET_N as u16 != 0) as u8, - if s.isr & isr::CODEC_MODE as u16 != 0 { "quad" } else { "indigo" }, - ).unwrap(); - - writeln!(writer, "DMA enable: 0x{:02x} codeca={} codecb={} aes_tx={} aes_rx={}", - s.dma_enable, - (s.dma_enable & DMA_EN_CODECA != 0) as u8, - (s.dma_enable & DMA_EN_CODECB != 0) as u8, - (s.dma_enable & DMA_EN_AES_TX != 0) as u8, - (s.dma_enable & DMA_EN_AES_RX != 0) as u8, - ).unwrap(); - // dma_drive uses physical HPC3 channel bits (bit N = PBUS channel N) - writeln!(writer, "DMA drive: 0x{:02x} (physical HPC3 channel bitmask)", s.dma_drive).unwrap(); - - for i in 0..3 { - let master = if s.bres_clock_sel[i] == 0 { 48000u32 } else { 44100 }; - writeln!(writer, "BRES{}: sel={} ({} Hz master) inc={} modctrl={} → {}Hz", - i + 1, s.bres_clock_sel[i], master, - s.bres_clock_inc[i], s.bres_clock_modctrl[i], - s.bres_clock_rate[i], - ).unwrap(); - } - - let mode_str = |m| match m { 1 => "mono", 2 => "stereo", 3 => "quad", _ => "off" }; - // bres=0 means CLKID 0: no generator selected. - - let (ca_ch, ca_clk, ca_mode) = s.codeca_cfg(); - let mute = (s.codeca_ctrl[1] & CODECA_CTRL2_MUTE) != 0; - let la = (s.codeca_ctrl[2] >> CODECA_CTRL2_LA_SHIFT) & CODECA_CTRL2_ATTEN_MASK; - let ra = (s.codeca_ctrl[2] >> CODECA_CTRL2_RA_SHIFT) & CODECA_CTRL2_ATTEN_MASK; - writeln!(writer, "Codec A: ch={} bres={} rate={}Hz mode={}", - ca_ch, ca_clk, s.bres_rate(ca_clk), mode_str(ca_mode)).unwrap(); - writeln!(writer, " ctrl1=0x{:04x} ctrl2=[0x{:04x} 0x{:04x}] mute={} atten_l=-{:.1}dB atten_r=-{:.1}dB", - s.codeca_ctrl[0], s.codeca_ctrl[1], s.codeca_ctrl[2], - mute as u8, la as f32 * 1.5, ra as f32 * 1.5).unwrap(); - writeln!(writer, "Volume (MDAC): left=0x{:02x} ({}) right=0x{:02x} ({})", - s.vol_left, s.vol_left, s.vol_right, s.vol_right).unwrap(); - - let (cb_ch, cb_clk, cb_mode) = s.codecb_cfg(); - writeln!(writer, "Codec B: ch={} bres={} rate={}Hz mode={}", - cb_ch, cb_clk, s.bres_rate(cb_clk), mode_str(cb_mode)).unwrap(); - - let (at_ch, at_clk, _) = s.aestx_cfg(); - let (ar_ch, ar_clk, _) = s.aesrx_cfg(); - writeln!(writer, "AES TX: ch={} bres={} rate={}Hz", at_ch, at_clk, s.bres_rate(at_clk)).unwrap(); - writeln!(writer, "AES RX: ch={} bres={} rate={}Hz", ar_ch, ar_clk, s.bres_rate(ar_clk)).unwrap(); - drop(s); - - let ca = self.ca_state.lock(); - writeln!(writer, "Codec A out: {} pitch: {} prebuf: {} prebuffering: {} timer: {}", - ca.out.as_ref().map_or("none".to_string(), |o| format!("{}Hz", o.stream_rate)), - ca.resampler.as_ref().map_or("none".to_string(), |r| format!("{}Hz", r.in_rate)), - ca.prebuf.len() / 2, - ca.prebuffering, - ca.timer_id.map_or("none".to_string(), |id| format!("{:#x}", id)), - ).unwrap(); - writeln!(writer, "Codec A timer: reads ch={} calls={} frames={} dry reads={}", - ca.armed_ch.map_or("-".to_string(), |c| c.to_string()), ca.calls, ca.frames, ca.dry_reads).unwrap(); - drop(ca); - writeln!(writer, "cpal underruns (samples): {}", self.underruns.load(Ordering::Relaxed)).unwrap(); - - writeln!(writer, "Codec B timer: {}", - self.cb_state.lock().timer_id.map_or("none".to_string(), |id| format!("{:#x}", id))).unwrap(); - writeln!(writer, "AES TX timer: {}", - self.at_state.lock().timer_id.map_or("none".to_string(), |id| format!("{:#x}", id))).unwrap(); - let ar = self.ar_state.lock(); - writeln!(writer, "AES RX timer: {} loopback_len={}", - ar.timer_id.map_or("none".to_string(), |id| format!("{:#x}", id)), - ar.loopback.len(), - ).unwrap(); - drop(ar); - let log: Vec<(u16, [u16; 4])> = self.state.lock().iar_log.iter().copied().collect(); - writeln!(writer, "Recent indirect accesses (IAR: IDR0 IDR1 IDR2 IDR3), oldest first:").unwrap(); - for (iar, idr) in log { - writeln!(writer, " {:04x}{}: {:04x} {:04x} {:04x} {:04x}", iar, - if iar & IAR_ACCESS_READ != 0 { " (read)" } else { "" }, - idr[0], idr[1], idr[2], idr[3]).unwrap(); - } - } - _ => return Err("Usage: hal2 status".to_string()), - } - Ok(()) + /// Only codec A plays to the host. + fn audio_report(&self) -> Option { + // A codec's rate is the guest's while its timer runs; codec A's also + // needs its channel to be supplying frames. + let (armed_b, armed_a) = (self.cb_state.lock().timer_id.is_some(), self.ca_state.lock().timer_id.is_some()); + let rates = { + let s = self.state.lock(); + let rate = |(_, clk, _): (usize, usize, usize), armed: bool| armed.then(|| s.bres_rate(clk)).filter(|&r| r > 0); + [rate(s.codecb_cfg(), armed_b), rate(s.codeca_cfg(), armed_a && self.meter.playing())] + }; + Some(self.meter.report(&rates, self.ca_state.lock().out.as_ref(), true)) } } @@ -1329,6 +1233,57 @@ mod tests { count / 2 // stereo pairs → frames } + /// `audio status` reports codec A's frames, rate and the host stream. + #[test] + fn audio_status_reports_codec_a_and_the_host_stream() { + let h = Hal2::new(vec![]); + { + let mut s = h.state.lock(); + s.bres_clock_rate[0] = 48000; + s.codeca_ctrl[0] = (1 << CTRL1_CLOCK_SHIFT | (MODE_STEREO as u16) << CTRL1_MODE_SHIFT) as u16; + } + h.meter.moved(1, 12); + let (prod, _cons) = RingBuffer::::new(64); + h.ca_state.lock().out = Some(AudioOut::detached(h.meter.clone(), 44100, prod)); + // The rate is the guest's only while codec A's timer runs and its + // channel supplies frames. + h.ca_state.lock().timer_id = Some(1); + assert!(h.audio_report().unwrap().contains("analog out: 12 frames moved, guest rate off\n")); + h.ca_state.lock().out.as_mut().unwrap().push_frame(&[1, 2]); + assert!(h.audio_report().unwrap().contains("analog out: 12 frames moved, guest rate 48000 Hz\n")); + h.ca_state.lock().timer_id = None; + h.meter.stopped(); + assert_eq!( + h.audio_report().as_deref(), + Some("audio: HAL2\n\ + \x20 analog in: 0 frames moved, guest rate off\n\ + \x20 analog out: 12 frames moved, guest rate off\n\ + \x20 host underruns: 0 frames\n\ + \x20 dropped by the host: 0 frames\n\ + \x20 host output: test at 44100 Hz, 2 channels\n") + ); + } + + /// Disabling codec A's DMA ends the card's playing: the host's silence + /// after a sound is not an underrun, and the next frame starts it again. + #[test] + fn disabling_codec_a_ends_playing() { + let h = Hal2::new(vec![]); + let (prod, mut cons) = RingBuffer::::new(64); + h.ca_state.lock().out = Some(AudioOut::detached(h.meter.clone(), 48000, prod)); + let underrun = |h: &Hal2, cons: &mut rtrb::Consumer| { + crate::host_audio::count_underrun(crate::host_audio::pop_frames(cons, 2, &mut [0i16; 2], |v| v), &h.meter); + h.meter.underruns() + }; + assert_eq!(underrun(&h, &mut cons), 0, "idle"); + h.ca_state.lock().out.as_mut().unwrap().push_frame(&[1, 2]); + cons.pop().unwrap(); + cons.pop().unwrap(); + assert_eq!(underrun(&h, &mut cons), 1, "playing"); + h.disarm_codeca(); + assert_eq!(underrun(&h, &mut cons), 1, "disabled"); + } + #[test] fn resampler_passthrough() { // 1:1 — every input frame produces exactly one output frame @@ -1482,53 +1437,93 @@ mod host_tests { assert_tones(&heard, 2, 48000, left, right, 15000); } + /// With no host output the card still counts the frames its channel + /// supplies, is playing while it supplies them, and stops when it does not. + #[test] + fn a_card_with_no_host_output_plays_while_its_channel_has_frames() { + let dma: Arc = Arc::new(Looping { words: vec![0x1234; 8], at: Default::default(), late: AtomicBool::new(false) }); + let client: Arc = dma.clone(); + let meter = Meter::new("test", &["analog in", "analog out"]); + drain_without_host(&client, MODE_STEREO, 4, &meter); + assert_eq!((meter.frames(1), meter.playing()), (4, true)); + dma.late.store(true, Ordering::Relaxed); + drain_without_host(&client, MODE_STEREO, 4, &meter); + assert_eq!((meter.frames(1), meter.playing()), (4, false)); + } + /// Codec A playing a 440 Hz tone on the left and 880 Hz on the right, - /// the guest falling behind for 0.3 s so the host stream runs dry, then - /// catching up. Both sides of the gap must be the tone with each - /// channel on its own side, as long as the channel moved, and the gap - /// must count as underruns. On an `[audio] file` this runs everywhere; - /// on the real device it checks cpal and the host's sound server too. - fn a_tone_survives_an_underrun(backend: Backend) { - let Some(ear) = Listener::new(backend, "hal2-underrun") else { return }; - // 11 and 22 cycles fill the 1200-frame buffer exactly. - let tone = tones(1200, 48000, 440.0, 880.0, 16000.0); - let dma = Arc::new(Looping { words: tone.iter().map(|&v| u32::from(v as u16)).collect(), at: Default::default(), late: AtomicBool::new(false) }); - let h = Hal2::with_audio(vec![dma.clone()], ear.cfg.clone()); - h.set_timer_manager(Arc::new(TimerManager::new())); - Device::start(&h); - { - let mut s = h.state.lock(); - s.bres_clock_rate[0] = 48000; - s.codeca_ctrl[0] = (1 << CTRL1_CLOCK_SHIFT | (MODE_STEREO as u16) << CTRL1_MODE_SHIFT) as u16; - s.dma_enable = DMA_EN_CODECA; + /// its HPC3 channel running out for 0.3 s (a chain that ended, which the + /// channel reports as nothing to read) so the host stream runs dry, then + /// refilled (see [`a_tone_survives_a_pause`]). + struct Codec { + h: Hal2, + dma: Arc, + started: AtomicBool, + } + + impl CardUnderTest for Codec { + const NAME: &'static str = "hal2-underrun"; + const PAUSE_IS_STALL: bool = false; + fn build(cfg: &AudioConfig) -> Self { + // 11 and 22 cycles fill the 1200-frame buffer exactly. + let tone = tones(1200, 48000, 440.0, 880.0, 16000.0); + let dma = Arc::new(Looping { words: tone.iter().map(|&v| u32::from(v as u16)).collect(), at: Default::default(), late: AtomicBool::new(false) }); + let h = Hal2::with_audio(vec![dma.clone()], cfg.clone()); + h.set_timer_manager(Arc::new(TimerManager::new())); + Device::start(&h); + { + let mut s = h.state.lock(); + s.bres_clock_rate[0] = 48000; + s.codeca_ctrl[0] = (1 << CTRL1_CLOCK_SHIFT | (MODE_STEREO as u16) << CTRL1_MODE_SHIFT) as u16; + s.dma_enable = DMA_EN_CODECA; + } + Self { h, dma, started: AtomicBool::new(false) } + } + fn tone(&self) -> (f64, f64) { + (440.0, 880.0) + } + fn rate(&self) -> f64 { + 48000.0 + } + fn play(&self) { + self.dma.late.store(false, Ordering::Relaxed); + if !self.started.swap(true, Ordering::Relaxed) { + self.h.apply_dma_enable(0, DMA_EN_CODECA); + } + } + /// The channel runs out at the next whole frame, so the pause is + /// exact before the card's count is read. + fn pause(&self) { + self.dma.late.store(true, Ordering::Relaxed); + let mut tries = 0; + while self.dma.at.load(Ordering::Relaxed) % 2 == 1 { + tries += 1; + assert!(tries < 500, "the channel never reached a whole frame"); + std::thread::sleep(Duration::from_millis(1)); + } + } + fn wait(&self, ms: u64) { + std::thread::sleep(Duration::from_millis(ms)); + } + fn frames(&self) -> f64 { + self.dma.at.load(Ordering::Relaxed) as f64 / 2.0 + } + fn meter(&self) -> &Meter { + &self.h.meter + } + fn finish(&self) { + Device::stop(&self.h); } - let frames = || dma.at.load(Ordering::Relaxed) as f64 / 2.0; - h.apply_dma_enable(0, DMA_EN_CODECA); - std::thread::sleep(Duration::from_millis(600)); - dma.late.store(true, Ordering::Relaxed); - let (first, before) = (frames(), h.underrun_count()); - std::thread::sleep(Duration::from_millis(300)); - let (paused, underran) = (frames(), h.underrun_count() - before); - dma.late.store(false, Ordering::Relaxed); - std::thread::sleep(Duration::from_millis(600)); - dma.late.store(true, Ordering::Relaxed); - let second = frames() - paused; - // What the host still holds plays out. - std::thread::sleep(Duration::from_millis(300)); - Device::stop(&h); - let heard = ear.heard(); - assert_a_tone_either_side_of_a_pause(&heard, 440.0, 880.0, 8000, [first / 48000.0, second / 48000.0]); - assert!(underran > 0, "the host stream ran dry while the guest was late"); } #[test] - fn a_tone_survives_an_underrun_into_a_file() { - a_tone_survives_an_underrun(Backend::File); + fn a_tone_survives_a_pause_into_a_file() { + a_tone_survives_a_pause::(Backend::File); } #[test] - fn a_tone_survives_an_underrun_on_the_real_device() { - a_tone_survives_an_underrun(Backend::RealDevice); + fn a_tone_survives_a_pause_on_the_real_device() { + a_tone_survives_a_pause::(Backend::RealDevice); } } diff --git a/src/dev/host_pcm.rs b/src/dev/host_pcm.rs index 6cd192ffc..1b476e3ab 100644 --- a/src/dev/host_pcm.rs +++ b/src/dev/host_pcm.rs @@ -50,9 +50,8 @@ impl Sink { } /// Play stereo frames the card produced at `rate` Hz. A muted output - /// still moves the ring; the host and the WAV get silence. Returns the - /// host ring's free and total samples. - pub fn play(&mut self, pcm: &[i16], rate: u32, muted: bool) -> Option<(usize, usize)> { + /// still moves the ring; the host and the WAV get silence. + pub fn play(&mut self, pcm: &[i16], rate: u32, muted: bool) { let silence; let host_pcm = if muted { silence = vec![0i16; pcm.len()]; @@ -65,7 +64,7 @@ impl Sink { *rs = Resampler::new(rate, out.stream_rate); } for p in host_pcm.chunks_exact(PCM_CHANNELS) { - rs.push(p[0], p[1], &mut out.producer); + out.push(rs, p[0], p[1]); } } if let Some(w) = self.wav.as_mut() { @@ -74,7 +73,6 @@ impl Sink { if let Some(t) = self.tap.as_ref() { t.lock().extend_from_slice(pcm); } - self.host.as_ref().map(|(out, _)| (out.producer.slots(), out.producer.buffer().capacity())) } } @@ -267,10 +265,8 @@ impl PcmOut { } /// Mix what is staged and play it at `rate` Hz. A stream whose engine is - /// not running contributes nothing and loses what it staged. Returns - /// the frames the host ring had no room for, or `None` without a host - /// stream. - pub fn flush(&mut self, rate: u32, analog_on: bool, spdif_on: bool) -> Option { + /// not running contributes nothing and loses what it staged. + pub fn flush(&mut self, rate: u32, analog_on: bool, spdif_on: bool) { if !analog_on { self.analog.clear(); } @@ -290,7 +286,6 @@ impl PcmOut { #[cfg(not(test))] let no_host_channels = PCM_CHANNELS; let chans = self.host.as_ref().map_or(no_host_channels, |(out, _)| out.channels); - let mut dropped = 0; if n > 0 { if self.mix.src != slots || self.mix.dst != chans { self.mix = Downmix::new(slots, chans); @@ -331,9 +326,7 @@ impl PcmOut { // the channels of every later frame would shift; one that // fits is published whole. for f in self.resampled.chunks_exact(chans) { - if !crate::host_audio::push_frame(&mut out.producer, f) { - dropped += 1; - } + out.push_frame(f); } } } @@ -344,7 +337,6 @@ impl PcmOut { v.drain(..v.len() - STAGE_MAX_FRAMES * w); } } - self.host.is_some().then_some(dropped) } } diff --git a/src/dev/hpc3.rs b/src/dev/hpc3.rs index dbbcb6eb8..6713e6721 100644 --- a/src/dev/hpc3.rs +++ b/src/dev/hpc3.rs @@ -1456,6 +1456,13 @@ impl Device for Hpc3 { fn is_running(&self) -> bool { self.ioc.is_running() } fn get_clock(&self) -> u64 { 0 } + fn audio_report(&self) -> Option { + match &self.hal2 { + Some(hal2) => hal2.audio_report(), + None => Some("audio: HAL2 absent: no_audio is set\n".to_string()), + } + } + fn register_commands(&self) -> Vec<(String, String)> { let mut cmds = vec![("hpc3".to_string(), "HPC3 commands: hpc3 status".to_string())]; cmds.push(("pdma".to_string(), "PDMA commands: pdma status | pdma chain | pdma dump [DEV]".to_string())); @@ -1471,7 +1478,6 @@ impl Device for Hpc3 { if self.scsi_dev1.is_some() { cmds.push(("scsi1".to_string(), "Second SCSI controller (fullhouse only) — same subcommands as `scsi`".to_string())); } - if let Some(hal2) = &self.hal2 { cmds.extend(hal2.register_commands()); } cmds } @@ -1596,13 +1602,6 @@ impl Device for Hpc3 { None => Err("scsi1: not available (guinness/Indy profile has a single SCSI controller)".to_string()), }; } - if cmd == "hal2" { - if let Some(hal2) = &self.hal2 { - return hal2.execute_command(cmd, args, writer); - } - let _ = writeln!(writer, "hal2: not available in headless mode"); - return Ok(()); - } if cmd == "rtc" { return self.rtc.execute_command(cmd, args, writer); } @@ -2488,6 +2487,21 @@ mod tests { std::fs::remove_dir_all(dir).unwrap(); } + /// `audio status` reaches HAL2 through the HPC3 when the machine has one, + /// and is not a command when `no_audio` leaves the HPC3 without it. + #[test] + fn audio_status_is_routed_to_hal2_only_when_the_machine_has_it() { + let hpc = |no_audio| Hpc3::with_net( + Arc::new(Mutex::new(Eeprom93c56::new())), Ioc::new(true), true, Arc::new(AtomicU64::new(0)), + NetworkConfig::default(), no_audio, AudioConfig::default(), String::new(), + RtcOffset::default(), true, Hpc3::new_scsi_buses(true), + ); + let with_hal2 = hpc(false); + let text = with_hal2.audio_report().expect("the HPC3 reports its HAL2"); + assert!(text.starts_with("audio: HAL2\n"), "{text}"); + assert_eq!(hpc(true).audio_report().as_deref(), Some("audio: HAL2 absent: no_audio is set\n")); + } + /// One channel per ops group: PBUS, SCSI, enet RX, enet TX. All twelve go /// through the same record, so a group-specific field such as `even_high` /// still has to survive on every channel. diff --git a/src/dev/ice1724.rs b/src/dev/ice1724.rs index 83376bed4..b42e4ee36 100644 --- a/src/dev/ice1724.rs +++ b/src/dev/ice1724.rs @@ -115,8 +115,8 @@ //! write after its previous read reaches only about 1 ms past it (90 //! frames past a position about 44 frames back), so a hold-up of more //! than about 1 ms there plays up to 0.5 ms of the previous lap. -//! * `dropped_frames` counts frames played into a host ring left with no -//! room. +//! * The frames each engine moves, and those a host ring had no room for, +//! are counted in the card's [`Meter`] like every audio card's. //! * The interleaved engine's slots, and the S/PDIF engine, play through one //! host stream with as many channels as the host device has (7.1, 5.1, //! quad or stereo). Which speaker a slot drives is not established; the @@ -148,7 +148,7 @@ use parking_lot::{Condvar, Mutex, MutexGuard}; use crate::config::AudioConfig; use crate::dev::host_pcm::{CardClock, PcmOut}; use crate::devlog::LogModule; -use crate::host_audio::FrameResampler; +use crate::host_audio::{FrameResampler, Meter}; use crate::hptimer::{TimerId, TimerManager, TimerReturn}; use crate::pci::{Bar, PciConfig, PciConfigPolicy, PciFunction, PciFunctionState, PciRegisterPolicy, PCI_COMMAND_IO, PCI_INTA}; use crate::snapshot::{field, field_bool, field_u32, field_u64, field_u8, field_u8s, load_u16_slice, StateTable}; @@ -425,14 +425,8 @@ impl Engine { /// comparing against a guest driver's intent. #[derive(Clone, Copy, Default, PartialEq, Eq, Debug)] pub struct Stats { - /// Frames the interleaved engine moved. - pub analog_frames: u64, /// The last dword of the last analog chunk moved. pub analog_last: u32, - pub spdif_frames: u64, - pub capture_frames: u64, - /// Frames the host stream had no room for. - pub dropped_frames: u64, pub ak4381_writes: u32, pub ak4355_writes: u32, /// Converter frames refused. @@ -686,6 +680,8 @@ pub struct Inner { /// `[audio]` settings once host output is enabled. audio_cfg: Mutex>, sink: Mutex>, + /// What the engines have moved and the host stream has done. + meter: Arc, /// Accesses that nothing establishes, counted. unexpected: AtomicU64, /// The messages behind them, for tests. @@ -737,6 +733,7 @@ impl Inner { timers: OnceLock::new(), audio_cfg: Mutex::new(None), sink: Mutex::new(None), + meter: Meter::new(if variant == Variant::Dm8 { "ICE1724 (DM8)" } else { "ICE1724 (AC'97)" }, &["analog in", "analog out", "S/PDIF out"]), unexpected: AtomicU64::new(0), #[cfg(test)] seen: Mutex::new(Vec::new()), @@ -830,6 +827,9 @@ impl Inner { /// Replace the pending timer with one for the engines' present state. fn arm_timer(&self, s: &mut State, now: i64) { + if !(s.eng[ENG_PDMAI].active || s.eng[ENG_PDMA4].active) { + self.meter.stopped(); + } s.timer_gen += 1; if let Some(id) = s.timer.take() { if let Some(tm) = self.timers.get() { @@ -876,6 +876,7 @@ impl Inner { } fn pause(&self) { + self.meter.stopped(); self.stop_clock(); self.armed.store(false, Ordering::SeqCst); { @@ -917,7 +918,7 @@ impl Inner { } } let ring = |rate: u32| rate as usize * 2 / 5; - let host = crate::host_audio::open_output_channels(&cfg, MAX_HOST_CHANNELS, Arc::new(AtomicU64::new(0)), Arc::new(AtomicBool::new(true)), ring, "ICE1724 audio", "IRIS_ICE1724_AUDIO_CAPTURE"); + let host = crate::host_audio::open_output_channels(&cfg, MAX_HOST_CHANNELS, self.meter.clone(), ring, "ICE1724 audio", "IRIS_ICE1724_AUDIO_CAPTURE"); crate::dlog!(LogModule::Ice1724, "ice1724: host audio {}", if host.is_some() { "open" } else { "failed to open" }); let host = host.map(|out| { let rs = FrameResampler::new(rate, out.stream_rate, out.channels); @@ -1028,15 +1029,15 @@ impl Inner { if !failed { s.stats.analog_last = u32::from_le_bytes(buf[bytes - 4..].try_into().unwrap()); } - s.stats.analog_frames += frames; + self.meter.moved(1, frames); } ENG_PDMA4 => { if let Some(sink) = self.sink.lock().as_mut() { sink.spdif_stage().extend(buf.as_chunks::<4>().0.iter().map(|d| i16::from_le_bytes([d[2], d[3]]))); } - s.stats.spdif_frames += frames; + self.meter.moved(2, frames); } - ENG_RDMA0 => s.stats.capture_frames += frames, + ENG_RDMA0 => self.meter.moved(0, frames), _ => {} } s.scratch = buf; @@ -1082,9 +1083,7 @@ impl Inner { } } if let Some(sink) = self.sink.lock().as_mut() { - if let Some(dropped) = sink.flush(s.rate, s.eng[ENG_PDMAI].active, s.eng[ENG_PDMA4].active) { - s.stats.dropped_frames += dropped; - } + sink.flush(s.rate, s.eng[ENG_PDMAI].active, s.eng[ENG_PDMA4].active); } self.update_irq(s); } @@ -1685,27 +1684,17 @@ impl Device for Ice1724 { 0 } - fn register_commands(&self) -> Vec<(String, String)> { - vec![("ice1724".into(), "ICE1724 audio controller: ice1724 status".into())] - } - - fn execute_command(&self, cmd: &str, args: &[&str], mut w: Box) -> Result<(), String> { - use std::io::Write as _; - if cmd != "ice1724" || args != ["status"] { - return Err("Usage: ice1724 status".into()); - } - let st = self.stats(); - let _ = writeln!( - w, - "frames: analog {} (last dword {:#010x}), S/PDIF {}, capture {}, dropped by the host {}", - st.analog_frames, st.analog_last, st.spdif_frames, st.capture_frames, st.dropped_frames - ); - let _ = writeln!( - w, - "converter writes: front {}, surround {}, refused {}; accesses nothing establishes: {}", - st.ak4381_writes, st.ak4355_writes, st.codec_rejects, self.unexpected() - ); - Ok(()) + /// The counts are as of the last pass of the card's timer: a query + /// moves nothing. + fn audio_report(&self) -> Option { + let i = &self.inner; + let rates = { + let s = i.state.lock(); + [ENG_RDMA0, ENG_PDMAI, ENG_PDMA4].map(|e| s.eng[e].active.then_some(s.rate)) + }; + let sink = i.sink.lock(); + let host = sink.as_ref().and_then(|s| s.host.as_ref()).map(|(out, _)| out); + Some(i.meter.report(&rates, host, i.audio_cfg.lock().is_some())) } } @@ -1816,11 +1805,7 @@ impl Saveable for Ice1724 { .u8s("ak4381", &s.ak4381) .u8s("ak4355", &s.ak4355) .u16s("ac97_regs", &s.ac97) - .u64("analog_frames", s.stats.analog_frames) .u32("analog_last", s.stats.analog_last) - .u64("spdif_frames", s.stats.spdif_frames) - .u64("capture_frames", s.stats.capture_frames) - .u64("dropped_frames", s.stats.dropped_frames) .u32("ak4381_writes", s.stats.ak4381_writes) .u32("ak4355_writes", s.stats.ak4355_writes) .u32("codec_rejects", s.stats.codec_rejects) @@ -1874,11 +1859,7 @@ impl Saveable for Ice1724 { ak4355: field_u8s(v, "ak4355")?, ac97, stats: Stats { - analog_frames: field_u64(v, "analog_frames")?, analog_last: field_u32(v, "analog_last")?, - spdif_frames: field_u64(v, "spdif_frames")?, - capture_frames: field_u64(v, "capture_frames")?, - dropped_frames: field_u64(v, "dropped_frames")?, ak4381_writes: field_u32(v, "ak4381_writes")?, ak4355_writes: field_u32(v, "ak4355_writes")?, codec_rejects: field_u32(v, "codec_rejects")?, diff --git a/src/dev/ice1724/tests.rs b/src/dev/ice1724/tests.rs index ae79cc3bb..4162db8ad 100644 --- a/src/dev/ice1724/tests.rs +++ b/src/dev/ice1724/tests.rs @@ -15,6 +15,8 @@ use super::*; use crate::dev::host_pcm::test_time::{FakeNs, TestTime}; use crate::dev::host_pcm::PcmOut; +use crate::host_audio::test_signal::{a_tone_survives_a_pause, channel, peak, Backend, CardUnderTest, Heard}; +use crate::host_audio::Meter; use crate::host_audio::{FrameResampler, HostOut}; use crate::irq::LevelProbe; use crate::pci::{PciDma, PciDmaStatus, PCI_COMMAND_IO}; @@ -375,7 +377,7 @@ fn a_system_reset_stops_a_running_engine() { mt_wb(&c, 0x03, 0xfe); mt_wb(&c, 0x18, 0x01); step(&c, 1_000_000); - assert_eq!(c.stats().analog_frames, 44); + assert_eq!(frames(&c, 1), 44); c.state().config().reset(); c.reset(); @@ -386,7 +388,7 @@ fn a_system_reset_stops_a_running_engine() { assert_eq!(mt_rb(&c, 0x18), 0); assert_eq!(cfg_b(&c, 0x3c), 0xff); step(&c, 1_000_000); - assert_eq!(c.stats().analog_frames, 44, "a stopped engine moves nothing"); + assert_eq!(frames(&c, 1), 44, "a stopped engine moves nothing"); } // ---- I2C EEPROM ---- @@ -573,7 +575,7 @@ fn playback_raises_its_interrupt_on_the_exact_frame() { mt_wb(&r, 0x18, 0x00); // Unmask the interleaved stream and the multi-channel source. - let first_run = r.stats().analog_frames; + let first_run = frames(&r, 1); assert_eq!(first_run, 240); program_playback(&r); mt_wb(&r, 0x03, 0xfe); @@ -594,9 +596,9 @@ fn playback_raises_its_interrupt_on_the_exact_frame() { assert!(inta(&r) && r.irq.level()); assert_eq!(mt_rw(&r, 0x14), 959 - 480); assert_eq!(mt_rl(&r, 0x10), BUFFER as u32 + 480 * 4); - assert_eq!(r.stats().analog_frames, first_run + 240); + assert_eq!(frames(&r, 1), first_run + 240); assert_eq!(r.stats().analog_last, 0x0100_0000 + 479); - assert_eq!(r.stats().dropped_frames, 0); + assert_eq!(dropped_frames(&r), 0); // Write 1 to clear; the macro bit and the line follow. mt_wb(&r, 0x00, 0x01); @@ -816,7 +818,7 @@ fn a_stopped_engine_adds_nothing() { /// A host stream behind a ring the test reads back, at `rate`. fn detached_host(r: &Rig, rate: u32, channels: usize) -> rtrb::Consumer { let (p, c) = rtrb::RingBuffer::::new(1 << 16); - let out = HostOut::detached_channels(rate, channels, p); + let out = HostOut::detached_channels(r.meter.clone(), rate, channels, p); let rs = FrameResampler::new(48000, rate, channels); *r.sink.lock() = Some(PcmOut::new(Some((out, rs)), None)); c @@ -834,7 +836,7 @@ fn the_host_ring_gets_whole_frames_at_the_stream_rate() { step(&r, 1_000_000); let got: Vec = std::iter::from_fn(|| c.pop().ok()).collect(); assert_eq!(got.len(), frames * 8, "{rate} Hz"); - assert_eq!(r.stats().dropped_frames, 0); + assert_eq!(dropped_frames(&r), 0); // The interpolation settles on each channel's own level. let last = &got[got.len() - 8..]; assert_eq!(last, [0x100, 0x200, 0x300, 0x400, 0x500, 0x600, 0x700, 0x800], "{rate} Hz"); @@ -845,7 +847,7 @@ fn the_host_ring_gets_whole_frames_at_the_stream_rate() { fn a_full_host_ring_counts_dropped_frames() { let r = rig(Variant::Dm8); let (p, _c) = rtrb::RingBuffer::::new(20); - let out = HostOut::detached_channels(48000, 8, p); + let out = HostOut::detached_channels(r.meter.clone(), 48000, 8, p); *r.sink.lock() = Some(PcmOut::new(Some((out, FrameResampler::new(48000, 48000, 8))), None)); fill_slot_numbers(&r, 8); mt_wl(&r, 0x10, BUFFER as u32); @@ -853,7 +855,7 @@ fn a_full_host_ring_counts_dropped_frames() { mt_wb(&r, 0x18, 0x01); step(&r, 1_000_000); // Two whole frames fit in 20 samples. - assert_eq!(r.stats().dropped_frames, 46); + assert_eq!(dropped_frames(&r), 46); } #[test] @@ -866,7 +868,7 @@ fn pause_rate_and_clock_gate_stop_the_engine() { mt_wb(&r, 0x01, 0x08); mt_wb(&r, 0x18, 0x01); step(&r, 5_000_000); - assert_eq!(r.stats().analog_frames, 220); + assert_eq!(frames(&r, 1), 220); assert_eq!(mt_rw(&r, 0x14), 959 - 440); // Pause freezes the position; resume continues from it. @@ -901,7 +903,7 @@ fn slots_per_frame_follow_mt19() { mt_ww(&r, 0x14, 959); mt_wb(&r, 0x18, 0x01); step(&r, 1_000_000); - assert_eq!(r.stats().analog_frames, 48); + assert_eq!(frames(&r, 1), 48); assert_eq!(mt_rw(&r, 0x14), 959 - 48 * 8); // Six slots. mt_wb(&r, 0x18, 0); @@ -966,7 +968,7 @@ fn record_writes_silence_over_the_buffer() { // 24 frames: 48 dwords, past the 32-dword interval, short of the end. assert_eq!(mt_rb(&r, 0x00), 0x02); assert_eq!(mt_rw(&r, 0x24), 63 - 48); - assert_eq!(r.stats().capture_frames, 24); + assert_eq!(frames(&r, 0), 24); let m = r.ram.0.lock().unwrap(); let buf = &m[BUFFER as usize..BUFFER as usize + 512]; assert!(buf[..48 * 4].iter().all(|&b| b == 0)); @@ -989,7 +991,7 @@ fn spdif_and_stereo_engines_run_when_mt19_gives_them_slots() { mt_ww(&r, 0x44, 255); mt_wb(&r, 0x18, 0x80); step(&r, 1_000_000); - assert_eq!(r.stats().spdif_frames, 48); + assert_eq!(frames(&r, 2), 48); assert_eq!(mt_rw(&r, 0x44), 255 - 96); assert_eq!(mt_rl(&r, 0x40), BUFFER as u32 + 96 * 4); @@ -1023,7 +1025,7 @@ fn on_time_ticks_hold_nothing_back() { } assert_eq!(r.stalled_ns.load(Ordering::SeqCst), 0); // 100 flow ticks of 2 ms at 48 kHz. - assert_eq!(r.stats().analog_frames, 9600); + assert_eq!(frames(&r, 1), 9600); } /// A timer far behind its deadline means the host held up its thread: the @@ -1043,7 +1045,7 @@ fn a_held_up_timer_does_not_replay_the_gap() { r.fake_ns().store(500_000_000, Ordering::Relaxed); r.timer_fire(gen); // 500 ms late, 200 ms taken back: 300 ms of audio, not 500. - assert_eq!(r.stats().analog_frames, 300 * 48); + assert_eq!(frames(&r, 1), 300 * 48); assert_eq!(r.stalled_ns.load(Ordering::SeqCst), 200_000_000); // A tick on time wins a share back. let due = r.state.lock().timer_due; @@ -1059,12 +1061,12 @@ fn a_long_look_away_is_not_replayed_through_memory() { program_playback(&r); mt_wb(&r, 0x18, 0x01); step(&r, 1_000_000); - assert_eq!(r.stats().analog_frames, 48); + assert_eq!(frames(&r, 1), 48); step(&r, 3_000_000_000); - assert_eq!(r.stats().analog_frames, 48, "the frames of the gap were skipped"); + assert_eq!(frames(&r, 1), 48, "the frames of the gap were skipped"); assert!(seen(&r, "DMA clock jump skipped")); step(&r, 1_000_000); - assert_eq!(r.stats().analog_frames, 96, "and the clock goes on from the present"); + assert_eq!(frames(&r, 1), 96, "and the clock goes on from the present"); } const IRIX_RING_FRAMES: u64 = 1024; @@ -1156,18 +1158,18 @@ fn an_engine_not_steered_by_polls_runs_on_its_clock() { let mut w = IrixWriter::start(&r); step(&r, 1_000_000); w.poll(&r); - let at = r.stats().analog_frames; + let at = frames(&r, 1); step(&r, 60_000_000); - assert_eq!(r.stats().analog_frames - at, 2646, "60 ms with no poll"); + assert_eq!(frames(&r, 1) - at, 2646, "60 ms with no poll"); let r = rig(Variant::Dm8); let mut w = IrixWriter::start(&r); mt_wb(&r, 0x03, 0xfe); step(&r, 1_000_000); w.poll(&r); - let at = r.stats().analog_frames; + let at = frames(&r, 1); step(&r, 10_000_000); - assert_eq!(r.stats().analog_frames - at, 441, "10 ms with the interrupt unmasked"); + assert_eq!(frames(&r, 1) - at, 441, "10 ms with the interrupt unmasked"); } /// Polls further apart than the read-ahead leave the engine behind its @@ -1182,10 +1184,10 @@ fn a_held_engine_keeps_at_most_100_ms_to_make_up() { step(&r, 10_000_000); w.poll(&r); } - let at = r.stats().analog_frames; + let at = frames(&r, 1); // No poll for 60 ms: the engine runs on its clock again. step(&r, 60_000_000); - let burst = r.stats().analog_frames - at; + let burst = frames(&r, 1) - at; // 100 ms kept plus the 60 ms, at 44.1 kHz. assert!(burst <= 7056 + 66, "made up {burst} frames at once"); } @@ -1296,7 +1298,7 @@ fn the_ac97_variant_has_a_codec_and_no_converters() { program_playback(&r); mt_wb(&r, 0x18, 0x01); step(&r, 1_000_000); - assert_eq!(r.stats().analog_frames, 48); + assert_eq!(frames(&r, 1), 48); } #[test] @@ -1430,36 +1432,122 @@ fn behind_a_bridge_the_io_window_reaches_the_bars_and_the_slot_carries_dma_and_i assert_eq!(io(0x0012_3004), None); } +/// Frames an output has moved (0 analog in, 1 analog out, 2 S/PDIF out), the engines +/// brought up to date first. +fn frames(c: &Ice1724, output: usize) -> u64 { + c.stats(); + c.meter.frames(output) +} + +/// Frames the host ring refused, the engines brought up to date first. +fn dropped_frames(c: &Ice1724) -> u64 { + c.stats(); + c.meter.dropped() +} + // ---- monitor ---- +/// The card answers the monitor's `audio status`, and has no command of its +/// own. #[test] -fn the_monitor_reports_what_the_engines_did() { - use crate::traits::Device; +fn the_card_answers_audio_status_and_has_no_command_of_its_own() { + let r = rig(Variant::Dm8); + assert!(r.c.audio_report().is_some()); + assert!(r.register_commands().is_empty()); +} + +/// What the engines moved reaches the card's meter, which `audio status` +/// reports; with host output off it says where nothing went. +#[test] +fn audio_status_counts_the_frames_the_engines_moved() { let r = rig(Variant::Dm8); fill_playback_buffer(&r); program_playback(&r); mt_wb(&r, 0x18, 0x01); step(&r, 5_000_000); - struct Out(Arc>>); - impl std::io::Write for Out { - fn write(&mut self, b: &[u8]) -> std::io::Result { - self.0.lock().unwrap().extend_from_slice(b); - Ok(b.len()) - } - fn flush(&mut self) -> std::io::Result<()> { - Ok(()) - } - } - let buf = Arc::new(std::sync::Mutex::new(Vec::new())); - r.execute_command("ice1724", &["status"], Box::new(Out(buf.clone()))).unwrap(); - let text = String::from_utf8(buf.lock().unwrap().clone()).unwrap(); - assert!(text.contains("analog 240 (last dword 0x010001df)"), "{text}"); - assert!(r.execute_command("ice1724", &[], Box::new(Out(buf))).is_err()); - assert_eq!(r.register_commands().len(), 1); + frames(&r, 1); + assert_eq!( + r.c.audio_report().unwrap(), + "audio: ICE1724 (DM8)\n\ + \x20 analog in: 0 frames moved, guest rate off\n\ + \x20 analog out: 240 frames moved, guest rate 48000 Hz\n\ + \x20 S/PDIF out: 0 frames moved, guest rate off\n\ + \x20 host underruns: 0 frames\n\ + \x20 dropped by the host: 0 frames\n\ + \x20 host output: none (no_audio)\n" + ); +} + +/// With a host stream open the status names it, and the card counts underruns +/// only from the first frame its engine writes until the engine stops. +#[test] +fn audio_status_names_the_host_stream_and_underruns_count_only_while_playing() { + let r = rig(Variant::Dm8); + let (prod, mut cons) = rtrb::RingBuffer::::new(64); + let out = HostOut::detached(r.meter.clone(), 48000, prod); + let rs = FrameResampler::new(48000, 48000, 2); + *r.sink.lock() = Some(PcmOut::new(Some((out, rs)), None)); + let text = r.c.audio_report().unwrap(); + assert!(text.contains("host output: test at 48000 Hz, 2 channels"), "{text}"); + let silence = |c: &mut rtrb::Consumer| crate::host_audio::pop_frames(c, 2, &mut [0i16; 8], |v| v); + // Idle: the host's silence is not counted. Frames written by the running + // engine start it. + crate::host_audio::count_underrun(silence(&mut cons), &r.meter); + assert_eq!(r.meter.underruns(), 0); + fill_playback_buffer(&r); + program_playback(&r); + mt_wb(&r, 0x18, 0x01); + step(&r, 1_000_000); + cons.read_chunk(cons.slots()).unwrap().commit_all(); + crate::host_audio::count_underrun(silence(&mut cons), &r.meter); + assert_eq!(r.meter.underruns(), 4, "the engine runs, so silence is an underrun"); + // Stopping the engine ends it. + mt_wb(&r, 0x18, 0x00); + crate::host_audio::count_underrun(silence(&mut cons), &r.meter); + assert_eq!(r.meter.underruns(), 4, "stopped"); +} + +/// A machine pause ends playing too, with the engine still running. +#[test] +fn pausing_the_machine_ends_playing() { + let r = rig(Variant::Dm8); + let (prod, mut cons) = rtrb::RingBuffer::::new(64); + let out = HostOut::detached(r.meter.clone(), 48000, prod); + *r.sink.lock() = Some(PcmOut::new(Some((out, FrameResampler::new(48000, 48000, 2))), None)); + fill_playback_buffer(&r); + program_playback(&r); + mt_wb(&r, 0x18, 0x01); + step(&r, 1_000_000); + cons.read_chunk(cons.slots()).unwrap().commit_all(); + Device::stop(&r.c); + crate::host_audio::count_underrun(crate::host_audio::pop_frames(&mut cons, 2, &mut [0i16; 8], |v| v), &r.meter); + assert_eq!(r.meter.underruns(), 0, "paused"); } // ---- save and restore ---- +/// The meter's counts are this process's: a restored card starts them at +/// zero, and a snapshot saved before they moved out of the card's own state, +/// carrying the old frame fields, still loads. +#[test] +fn the_meter_is_not_saved_and_an_old_snapshot_still_loads() { + use crate::traits::Saveable; + let a = rig(Variant::Dm8); + fill_playback_buffer(&a); + program_playback(&a); + mt_wb(&a, 0x18, 0x01); + step(&a, 2_000_000); + assert!(a.meter.frames(1) > 0); + let mut saved = a.save_state(); + for key in ["analog_frames", "spdif_frames", "capture_frames", "dropped_frames"] { + assert!(saved.get(key).is_none(), "{key} is no longer saved"); + saved.as_table_mut().unwrap().insert(key.into(), crate::snapshot::hex_u64(99)); + } + let b = rig(Variant::Dm8); + b.load_state(&saved).expect("an old snapshot loads"); + assert_eq!(b.meter.frames(1), 0); +} + #[test] fn a_running_engine_resumes_where_it_was_saved() { use crate::traits::Saveable; @@ -1665,139 +1753,188 @@ fn a_big_endian_slot_word_through_a_real_pic_slot_plays_its_sample() { } /// The ICE1724 playing a tone, the guest stopping the output for 0.3 s so -/// the host stream runs dry, then starting it again. The guest steers like -/// IRIX: the engine's interrupt masked, the address read about every half -/// millisecond and eight-slot frames written a little ahead of it. In the -/// middle of each stretch the guest also looks away for 30 ms, which the -/// read-ahead hold must carry: a card that read on would play the ring's -/// previous lap again. Both sides of the gap must be the tone with the -/// front pair on its own sides, as long as the engine moved, and the gap -/// must count as underrun. The tone is in slots 0 and 1, which the host -/// gets at unity as its front pair, and it drifts in pitch so that no -/// frame is the same as one a lap earlier; with an `[audio] file` the -/// frames heard must follow one another in the guest's order, none -/// replayed. -fn a_tone_survives_an_underrun(backend: crate::host_audio::test_signal::Backend) { - use crate::host_audio::test_signal::*; - use std::time::{Duration, Instant}; - let exact = matches!(backend, Backend::File); - let Some(ear) = Listener::new(backend, "ice1724-underrun") else { return }; - const RATE: f64 = 48000.0; - let (left, right) = (440.0, 880.0); - let c = Ice1724::with_clock(Variant::Dm8, TestTime::clock()); - let ram = Arc::new(Ram(std::sync::Mutex::new(vec![0; 0x10_0000]))); - c.state().connect_dma(ram.clone()); - c.attached(); - map(&c); - c.set_timer_manager(Arc::new(TimerManager::new())); - c.enable_output(ear.cfg.clone()); - Device::start(&c); - - // Frame `n` of the tone is in slots 0 and 1 of a ring frame, each - // sample in the top half of its dword; the other six slots are silent. - // The pitch rises 2 Hz a second, well inside the 1% the check allows. - let tone = |hz: f64, n: u64| { - let t = n as f64 / RATE; - (16000.0 * (std::f64::consts::TAU * (hz * t + t * t)).sin()).round() as i16 - }; - let fill = |written: &mut u64, upto: u64| { - let mut m = ram.0.lock().unwrap(); - while *written < upto { - let at = BUFFER as usize + (*written % IRIX_RING_FRAMES) as usize * 32; - for (slot, hz) in [(0, left), (1, right)] { - let v = u32::from(tone(hz, *written) as u16) << 16; +/// the host stream runs dry, then starting it again (see +/// [`a_tone_survives_a_pause`]). The guest steers like IRIX: the engine's +/// interrupt masked, the address read about every half millisecond and +/// eight-slot frames written a little ahead of it. In the middle of each +/// stretch the guest also looks away for 30 ms, which the read-ahead hold +/// must carry: a card that read on would play the ring's previous lap +/// again. The tone is in slots 0 and 1, which the host gets at unity as its +/// front pair, and it drifts in pitch so that no frame is the same as one a +/// lap earlier; with an `[audio] file` the frames heard must follow one +/// another in the guest's order, none replayed. +struct Tezro { + c: Ice1724, + ram: Arc, + guest: std::sync::Mutex, +} + +/// Where the guest's writing has got to, and how long the host kept it away. +/// The hold lasts while reads come less than 50 ms apart; until the first +/// read after a start the card runs on its clock, through the lap written +/// before it. Each bound spans from before one read, or the start, to after +/// the next read, or the stop, so it covers the card's own instants. +#[derive(Default)] +struct Guest { + written: u64, + read: u64, + /// While the output runs: when it was started, and when the guest last + /// read the position. + started: Option, + last: Option, + longest_gap: std::time::Duration, + slowest_start: std::time::Duration, +} + +const TEZRO_RATE: f64 = 48000.0; +const TEZRO_TONE: (f64, f64) = (440.0, 880.0); + +/// Frame `n` of a tone at `hz`, rising 2 Hz a second, well inside the 1% the +/// check allows. +fn drifting_tone(hz: f64, n: u64) -> i16 { + let t = n as f64 / TEZRO_RATE; + (16000.0 * (std::f64::consts::TAU * (hz * t + t * t)).sin()).round() as i16 +} + +impl Tezro { + /// Write frames up to `upto`: the tone in slots 0 and 1 of a ring frame, + /// each sample in the top half of its dword, the other six slots silent. + fn fill(&self, g: &mut Guest, upto: u64) { + let mut m = self.ram.0.lock().unwrap(); + while g.written < upto { + let at = BUFFER as usize + (g.written % IRIX_RING_FRAMES) as usize * 32; + for (slot, hz) in [(0, TEZRO_TONE.0), (1, TEZRO_TONE.1)] { + let v = u32::from(drifting_tone(hz, g.written) as u16) << 16; m[at + slot * 4..at + slot * 4 + 4].copy_from_slice(&v.to_le_bytes()); } - *written += 1; + g.written += 1; } - }; - let position = |read: &mut u64| { - let pos = u64::from((mt_rl(&c, 0x10) - BUFFER as u32) / 32); - *read += (pos + IRIX_RING_FRAMES - *read % IRIX_RING_FRAMES) % IRIX_RING_FRAMES; - }; - // The guest writes two read-aheads past the position it reads. The - // card may run one read-ahead past that position before the write - // lands, and the position is at most one read-ahead past the one read - // before, whose write has landed: with two, every frame the card reads - // is written, however long the host holds the guest up between its - // read and its write. IRIX writes less ahead (see the module notes). - let lead = 2 * (u128::from(READ_AHEAD_NS) * 48000 / NS_PER_SEC) as u64; - // Eight slots to a frame, at the reset rate of 48 kHz: the host - // stream takes the frames unresampled. - mt_wb(&c, 0x19, 0); - mt_wl(&c, 0x10, BUFFER as u32); - mt_wl(&c, 0x14, IRIX_RING_FRAMES as u32 * 8 - 1); - let (mut written, mut read) = (0u64, 0u64); - // The hold lasts while reads come less than 50 ms apart; until the - // first read after a start the card runs on its clock, through the lap - // written before it. Each bound spans from before one read, or the - // start, to after the next read, or the stop, so it covers the card's - // own instants. - let (mut longest_gap, mut slowest_start) = (Duration::ZERO, Duration::ZERO); - // A stretch: write a lap from where the engine stopped, start it, and - // for 0.6 s read the position and write ahead of it about every half - // millisecond, looking away for 30 ms halfway; then stop it. - let mut stretch = || { - position(&mut read); - fill(&mut written, read + IRIX_RING_FRAMES); - let started = Instant::now(); - mt_wb(&c, 0x18, 0x01); - let mut last: Option = None; - for half in 0..2 { - let end = Instant::now() + Duration::from_millis(300); - while Instant::now() < end { - let before = Instant::now(); - position(&mut read); - match last { - Some(t) => longest_gap = longest_gap.max(t.elapsed()), - None => slowest_start = slowest_start.max(started.elapsed()), - } - last = Some(before); - fill(&mut written, read + lead); - std::thread::sleep(Duration::from_micros(500)); - } - if half == 0 { - std::thread::sleep(Duration::from_millis(30)); + } + + /// Read the engine's position. + fn position(&self, g: &mut Guest) { + let pos = u64::from((mt_rl(&self.c, 0x10) - BUFFER as u32) / 32); + g.read += (pos + IRIX_RING_FRAMES - g.read % IRIX_RING_FRAMES) % IRIX_RING_FRAMES; + } + + /// While the output runs, the guest reads the position and writes two + /// read-aheads past it about every half millisecond, for `ms`. The card + /// may run one read-ahead past that position before the write lands, and + /// the position is at most one read-ahead past the one read before, + /// whose write has landed: with two, every frame the card reads is + /// written, however long the host holds the guest up between its read + /// and its write. IRIX writes less ahead (see the module notes). + fn run(&self, ms: u64) { + let lead = 2 * (u128::from(READ_AHEAD_NS) * 48000 / NS_PER_SEC) as u64; + let mut g = self.guest.lock().unwrap(); + let end = std::time::Instant::now() + std::time::Duration::from_millis(ms); + while std::time::Instant::now() < end { + let before = std::time::Instant::now(); + self.position(&mut g); + match (g.last, g.started) { + (Some(t), _) => g.longest_gap = g.longest_gap.max(t.elapsed()), + (None, Some(t)) => g.slowest_start = g.slowest_start.max(t.elapsed()), + (None, None) => {} } + g.last = Some(before); + let upto = g.read + lead; + self.fill(&mut g, upto); + std::thread::sleep(std::time::Duration::from_micros(500)); } - mt_wb(&c, 0x18, 0x00); - longest_gap = longest_gap.max(last.map_or(Duration::ZERO, |t| t.elapsed())); - }; - let moved = || c.stats().analog_frames as f64; - let underruns = || c.sink.lock().as_ref().and_then(|s| s.host.as_ref()).map_or(0, |(h, _)| h.underruns.load(Ordering::Relaxed)); - stretch(); - let (first, before) = (moved(), underruns()); - std::thread::sleep(Duration::from_millis(300)); - let (paused, underran) = (moved(), underruns() - before); - stretch(); - let second = moved() - paused; - // What the host still holds plays out. - std::thread::sleep(Duration::from_millis(300)); - Device::stop(&c); - c.sink.lock().take(); - let heard = ear.heard(); - assert_a_tone_either_side_of_a_pause(&heard, left, right, 8000, [first / RATE, second / RATE]); - assert!(underran > 0, "the host stream ran dry while the output was stopped"); - assert_eq!(paused, first, "the engine moved while it was stopped"); - // A host that kept the guest from reading for 40 ms lets the 50 ms - // hold run out, or for 18 ms after a start lets the card through the - // 21 ms lap written ahead less the 1.5 ms it may read past that first - // read, as it would a real guest: the card then reads frames not yet - // written, and the order check below would be a false alarm. So would - // a host ring that dropped more frames than the check looks ahead. - let dropped = c.stats().dropped_frames; - let calm = longest_gap < Duration::from_millis(40) && slowest_start < Duration::from_millis(18) && dropped < 4800; - if !calm { - eprintln!("the guest was kept away for {longest_gap:?}, {slowest_start:?} after a start, {dropped} frames dropped: not checking the order of the frames"); } - if exact && calm { +} + +impl CardUnderTest for Tezro { + const NAME: &'static str = "ice1724-underrun"; + const PAUSE_IS_STALL: bool = false; + fn build(cfg: &crate::config::AudioConfig) -> Self { + let c = Ice1724::with_clock(Variant::Dm8, TestTime::clock()); + let ram = Arc::new(Ram(std::sync::Mutex::new(vec![0; 0x10_0000]))); + c.state().connect_dma(ram.clone()); + c.attached(); + map(&c); + c.set_timer_manager(Arc::new(TimerManager::new())); + c.enable_output(cfg.clone()); + Device::start(&c); + // Eight slots to a frame, at the reset rate of 48 kHz: the host + // stream takes the frames unresampled. + mt_wb(&c, 0x19, 0); + mt_wl(&c, 0x10, BUFFER as u32); + mt_wl(&c, 0x14, IRIX_RING_FRAMES as u32 * 8 - 1); + Self { c, ram, guest: Default::default() } + } + fn tone(&self) -> (f64, f64) { + TEZRO_TONE + } + fn rate(&self) -> f64 { + TEZRO_RATE + } + /// Write a lap from where the engine stopped, then start it. + fn play(&self) { + let mut g = self.guest.lock().unwrap(); + self.position(&mut g); + let upto = g.read + IRIX_RING_FRAMES; + self.fill(&mut g, upto); + g.started = Some(std::time::Instant::now()); + g.last = None; + mt_wb(&self.c, 0x18, 0x01); + } + fn pause(&self) { + mt_wb(&self.c, 0x18, 0x00); + let mut g = self.guest.lock().unwrap(); + g.longest_gap = g.longest_gap.max(g.last.map_or(std::time::Duration::ZERO, |t| t.elapsed())); + g.started = None; + g.last = None; + } + /// While the output runs the guest steers it, looking away for 30 ms in + /// the middle of a long stretch. + fn wait(&self, ms: u64) { + if self.guest.lock().unwrap().started.is_none() { + return std::thread::sleep(std::time::Duration::from_millis(ms)); + } + self.run(ms / 2); + if ms >= 600 { + std::thread::sleep(std::time::Duration::from_millis(30)); + } + self.run(ms - ms / 2); + } + fn frames(&self) -> f64 { + self.c.stats(); // brings the engine up to date + self.c.meter.frames(1) as f64 + } + fn meter(&self) -> &Meter { + &self.c.meter + } + fn finish(&self) { + Device::stop(&self.c); + self.c.sink.lock().take(); + } + /// A host that kept the guest from reading for 40 ms lets the 50 ms hold + /// run out, or for 18 ms after a start lets the card through the 21 ms + /// lap written ahead less the 1.5 ms it may read past that first read, + /// as it would a real guest: the card then reads frames not yet written, + /// and the order check would be a false alarm. So would a host ring that + /// dropped more frames than the check looks ahead. + fn check(&self, heard: &Heard, moved: f64, exact: bool) { + let g = self.guest.lock().unwrap(); + let dropped = self.c.meter.dropped(); + let (gap, start) = (g.longest_gap, g.slowest_start); + let ms = std::time::Duration::from_millis; + let calm = gap < ms(40) && start < ms(18) && dropped < 4800; + if !calm { + eprintln!("the guest was kept away for {gap:?}, {start:?} after a start, {dropped} frames dropped: not checking the order of the frames"); + } + if !(exact && calm) { + return; + } assert_eq!((heard.rate, heard.channels), (crate::host_audio::FILE_RATE, 2)); // The frames played, silence left out, are the guest's frames in // order: each is later in the stream than the one before and no // more than 100 ms after it. A replayed lap goes back. + let (left, right) = TEZRO_TONE; let mut n = 0u64; for (i, f) in heard.pcm.chunks_exact(heard.channels).filter(|f| f.iter().any(|&v| v != 0)).enumerate() { - let at = (n..n + 4800).find(|&k| f[0] == tone(left, k) && f[1] == tone(right, k)); + let at = (n..n + 4800).find(|&k| f[0] == drifting_tone(left, k) && f[1] == drifting_tone(right, k)); let Some(k) = at else { panic!("frame {i} of the sound ({}, {}) is not the guest's frame {n} or any of the next 4800", f[0], f[1]) }; n = k + 1; } @@ -1805,16 +1942,16 @@ fn a_tone_survives_an_underrun(backend: crate::host_audio::test_signal::Backend) for c in 0..2 { assert!(peak(&channel(&heard.pcm, 2, c)) >= 15800, "channel {c} peak {}", peak(&channel(&heard.pcm, 2, c))); } - assert!(n as f64 >= 0.5 * (first + second), "{n} of the {} frames the card moved were heard", first + second); + assert!(n as f64 >= 0.5 * moved, "{n} of the {moved} frames the card moved were heard"); } } #[test] -fn a_tone_survives_an_underrun_into_a_file() { - a_tone_survives_an_underrun(crate::host_audio::test_signal::Backend::File); +fn a_tone_survives_a_pause_into_a_file() { + a_tone_survives_a_pause::(Backend::File); } #[test] -fn a_tone_survives_an_underrun_on_the_real_device() { - a_tone_survives_an_underrun(crate::host_audio::test_signal::Backend::RealDevice); +fn a_tone_survives_a_pause_on_the_real_device() { + a_tone_survives_a_pause::(Backend::RealDevice); } diff --git a/src/dev/mace_audio.rs b/src/dev/mace_audio.rs index 95e9b3b05..ed77e83bb 100644 --- a/src/dev/mace_audio.rs +++ b/src/dev/mace_audio.rs @@ -36,7 +36,7 @@ use parking_lot::Mutex; use crate::config::AudioConfig; use crate::dev::crime_mem::O2Memory; use crate::traits::BusDevice; -use crate::host_audio::{HostOut, Resampler}; +use crate::host_audio::{HostOut, Meter, Resampler}; /// Where the audio registers sit, and their 16 KB block. pub const MACE_AUDIO: u32 = 0x1f30_0000; @@ -282,7 +282,9 @@ pub struct MaceAudio { player: Mutex>, config: Mutex>, tried_open: AtomicBool, - underruns: Arc, + /// What the outputs have played (silence for a dry ring included) and + /// the host stream has done. + meter: Arc, /// For the trace: non-zero sample pairs each output played, and when /// that was last reported. heard: [AtomicU64; 2], @@ -312,7 +314,7 @@ impl MaceAudio { player: Mutex::new(None), config: Mutex::new(None), tried_open: AtomicBool::new(false), - underruns: Arc::new(AtomicU64::new(0)), + meter: Meter::new("MACE audio", &["analog in", "analog out 1", "analog out 2"]), heard: [AtomicU64::new(0), AtomicU64::new(0)], gaps: [AtomicU64::new(0), AtomicU64::new(0)], gap_items: [AtomicU64::new(0), AtomicU64::new(0)], @@ -508,7 +510,9 @@ impl MaceAudio { match st.adc_rate() { Some(rate) if st.ch[0].running() => { let c = &mut st.ch[0]; - for _ in 0..c.due(now, rate) { + let due = c.due(now, rate); + self.meter.moved(0, due); + for _ in 0..due { let next = (c.wptr + BLOCK) & PTR_MASK; if c.sub == 0 && next == c.rptr { break; // full: the engine never fills the last slot @@ -542,7 +546,9 @@ impl MaceAudio { let (gain_l, gain_r) = st.dac_gain(n); let c = &mut st.ch[n]; rates[out] = rate; - for _ in 0..c.due(now, rate) { + let due = c.due(now, rate); + self.meter.moved(out + 1, due); + for _ in 0..due { let mut item = (0i16, 0i16); if c.depth() == 0 { c.dry = c.dry.saturating_add(1); @@ -573,6 +579,9 @@ impl MaceAudio { pcm[out].push(item); } } + if rates == [0, 0] { + self.meter.stopped(); + } if pcm.iter().any(|p| !p.is_empty()) { st.played.push((pcm, rates)); } @@ -626,7 +635,7 @@ impl MaceAudio { if player.is_none() && !self.tried_open.swap(true, Ordering::Relaxed) { if let Some(cfg) = self.config.lock().clone() { let ring = |rate: u32| rate as usize * 2 / 5; // 200 ms of stereo - *player = crate::host_audio::open_output(&cfg, self.underruns.clone(), Arc::new(AtomicBool::new(true)), ring, "O2 audio", "IRIS_O2_AUDIO_CAPTURE") + *player = crate::host_audio::open_output(&cfg, self.meter.clone(), ring, "O2 audio", "IRIS_O2_AUDIO_CAPTURE") .map(|out| Player { out, rs: [None, None] }); } } @@ -644,7 +653,7 @@ impl MaceAudio { // The resampler writes into a ring; take its output back out. let (mut prod, mut cons) = rtrb::RingBuffer::::new(pcm[out].len() * 2 * (host as usize / rates[out] as usize + 2) + 8); for &(l, r) in &pcm[out] { - rs.push(l, r, &mut prod); + let _ = rs.push(l, r, &mut prod); // the scratch ring has room: nothing is refused } let mut k = 0; while let Ok(v) = cons.pop() { @@ -656,17 +665,17 @@ impl MaceAudio { k += 1; } } - push_mixed(&mut p.out.producer, &mixed); + push_mixed(&mut p.out, &mixed); } } /// Clamp the mixed stereo pairs to 16 bits and push each pair whole or not /// at all: with one slot left the left sample alone would go in and every /// later pair would be swapped. -fn push_mixed(prod: &mut rtrb::Producer, mixed: &[i32]) { +fn push_mixed(out: &mut HostOut, mixed: &[i32]) { for pair in mixed.chunks_exact(2) { let [l, r] = [pair[0], pair[1]].map(|v| v.clamp(i16::MIN as i32, i16::MAX as i32) as i16); - crate::host_audio::push_frame(prod, &[l, r]); + out.push_frame(&[l, r]); } } @@ -764,39 +773,36 @@ impl crate::traits::BusDevice for MaceAudio { impl crate::traits::Device for MaceAudio { fn step(&self, _cycles: u64) {} - fn stop(&self) {} + fn stop(&self) { + self.meter.stopped(); + } fn start(&self) {} fn is_running(&self) -> bool { true } fn get_clock(&self) -> u64 { 0 } + /// The counts are as of the last service pass: a query moves nothing. + fn audio_report(&self) -> Option { + let rates = { + let st = self.st.lock(); + // The converter's rate, while the channel that feeds it runs. + let on = |n: usize, rate: Option| rate.filter(|_| st.ch[n].running()); + [on(0, st.adc_rate()), on(1, st.dac_rate(1)), on(2, st.dac_rate(2))] + }; + let player = self.player.lock(); + Some(self.meter.report(&rates, player.as_ref().map(|p| &p.out), self.config.lock().is_some())) + } + fn register_commands(&self) -> Vec<(String, String)> { - vec![("audio".to_string(), "MACE audio + AD1843: audio status | audio codec".to_string())] + vec![("audio".to_string(), "audio [status]: the audio card's report | audio codec: the AD1843 registers".to_string())] } fn execute_command(&self, cmd: &str, args: &[&str], mut w: Box) -> Result<(), String> { use std::io::Write; - if cmd != "audio" { - return Err("Command not found".to_string()); + if cmd != "audio" || args != ["codec"] { + return Err("Usage: audio codec".to_string()); } - let st = self.st.lock(); - match args.first().copied().unwrap_or("status") { - "status" => { - writeln!(w, "MACE audio: control {:#x}, codec control {:#x}, mask {:#x}, host output {}", - st.ctl, st.codec_ctl, st.mask, if self.player.lock().is_some() { "open" } else { "closed" }).ok(); - for (n, name) in ["input", "output 1", "output 2"].iter().enumerate() { - let c = &st.ch[n]; - writeln!(w, " {name}: control {:#x} read {:#05x} write {:#05x} depth {} MSC {} {}", - c.ctl, c.rptr, c.wptr, c.depth(), c.msc, if c.running() { "running" } else { "stopped" }).ok(); - } - let rate = |r: Option| r.map_or("off".to_string(), |r| format!("{r} Hz")); - writeln!(w, " rates: DAC1 {} DAC2 {} ADC {}", rate(st.dac_rate(1)), rate(st.dac_rate(2)), rate(st.adc_rate())).ok(); - } - "codec" => { - for (i, v) in st.codec.iter().enumerate() { - writeln!(w, " AD1843 reg {i:2}: {v:#06x}").ok(); - } - } - _ => return Err("Usage: audio status | codec".to_string()), + for (i, v) in self.st.lock().codec.iter().enumerate() { + writeln!(w, " AD1843 reg {i:2}: {v:#06x}").map_err(|e| e.to_string())?; } Ok(()) } @@ -819,10 +825,12 @@ mod tests { fn a_pair_that_does_not_fit_is_dropped_whole() { // Three slots: the first pair fits and leaves one, which the left // sample of the second must not take. - let (mut p, mut c) = rtrb::RingBuffer::::new(3); - push_mixed(&mut p, &[1, -2, 40000, -40000]); + let (p, mut c) = rtrb::RingBuffer::::new(3); + let mut out = HostOut::detached(Meter::new("test", &[]), 48000, p); + push_mixed(&mut out, &[1, -2, 40000, -40000]); assert_eq!(std::iter::from_fn(|| c.pop().ok()).collect::>(), [1, -2]); - push_mixed(&mut p, &[40000, -40000]); + assert_eq!(out.meter.dropped(), 1, "the pair with no room is counted"); + push_mixed(&mut out, &[40000, -40000]); assert_eq!(std::iter::from_fn(|| c.pop().ok()).collect::>(), [i16::MAX, i16::MIN]); } @@ -964,6 +972,56 @@ mod tests { assert!((mu >> 32) as u32 > 0 && mu as u32 == 7, "MSC counts in the high word, UST stamped in the low"); } + /// Stopping the machine ends playing: the host's silence while it is + /// stopped is not an underrun. + #[test] + fn stopping_the_machine_ends_playing() { + use crate::traits::Device; + let a = MaceAudio::new(); + let (prod, mut cons) = rtrb::RingBuffer::::new(64); + let mut out = HostOut::detached(a.meter.clone(), 48000, prod); + out.push_frame(&[1, 2]); + cons.read_chunk(cons.slots()).unwrap().commit_all(); + let underrun = |cons: &mut rtrb::Consumer| { + crate::host_audio::count_underrun(crate::host_audio::pop_frames(cons, 2, &mut [0i16; 2], |v| v), &a.meter); + a.meter.underruns() + }; + assert_eq!(underrun(&mut cons), 1, "playing"); + a.stop(); + assert_eq!(underrun(&mut cons), 1, "stopped"); + } + + /// The frames each output played on the pacing clock reach the card's + /// meter and `audio status`. + #[test] + fn audio_status_counts_each_outputs_frames() { + let ram = O2Memory::single(8 << 20); + let a = MaceAudio::new(); + a.write(MACE_AUDIO, 0); + write_codec(&a, 28, 0x0800); + write_codec(&a, 17, 8000); + write_codec(&a, 15, 1 << 8); + write_codec(&a, 27, 1 << 8); + a.write(MACE_AUDIO + 0x40, CTRL_ENABLE); + let io = AudioIo { ram: &ram, ring_base: 0x0010_0000, ust: 0 }; + let t0 = Instant::now(); + a.poll_at(&io, t0); + a.poll_at(&io, t0 + std::time::Duration::from_millis(100)); + assert_eq!( + a.audio_report().unwrap(), + "audio: MACE audio\n\ + \x20 analog in: 0 frames moved, guest rate off\n\ + \x20 analog out 1: 800 frames moved, guest rate 8000 Hz\n\ + \x20 analog out 2: 0 frames moved, guest rate off\n\ + \x20 host underruns: 0 frames\n\ + \x20 dropped by the host: 0 frames\n\ + \x20 host output: none (no_audio)\n" + ); + use crate::traits::Device; + assert!(a.execute_command("audio", &["codec"], Box::new(std::io::sink())).is_ok()); + assert!(a.execute_command("audio", &["status"], Box::new(std::io::sink())).is_err(), "status is the monitor's"); + } + /// IRIX feeds an output ring by reading the read pointer about once a /// millisecond and setting the write pointer 17 frames past it at /// 8 kHz, which the block pointer rounds down to 16 (2 ms). The service @@ -1074,68 +1132,82 @@ mod tests { assert_tones(&heard, 2, 48000, left, right, 15000); } - /// The O2 playing a tone, the guest stopping the output for 0.3 s so - /// the host stream runs dry, then starting it again. Both sides of the - /// gap must be the tone with each channel on its own side, as long as - /// the ring moved, and the gap must count as underruns. The 512-pair - /// ring holds five and ten whole cycles, so the tones are 468.75 and - /// 937.5 Hz rather than 440 and 880. - fn a_tone_survives_an_underrun(backend: crate::host_audio::test_signal::Backend) { - use crate::host_audio::test_signal::*; - let Some(ear) = Listener::new(backend, "o2-underrun") else { return }; - let ram = O2Memory::single(8 << 20); - let a = MaceAudio::new(); - a.enable_output(ear.cfg.clone()); - a.write(MACE_AUDIO, 0); - write_codec(&a, 28, 0x0800); - write_codec(&a, 17, 48000); - write_codec(&a, 15, 1 << 8); - write_codec(&a, 27, 1 << 8); - write_codec(&a, 9, 0x0808); - let (left, right) = (5.0 * 48000.0 / 512.0, 10.0 * 48000.0 / 512.0); - let ring_base = 0x0010_0000u32; - for (i, &v) in tones(512, 48000, left, right, 16000.0).iter().enumerate() { - let o = ram.dma_offset(ring_base | 0x1000 | i as u32 * 4).unwrap(); - ram.put_be(o, 4, (i32::from(v) << 8) as u32); + use crate::host_audio::test_signal::{a_tone_survives_a_pause, tones, CardUnderTest}; + + /// The O2 playing a tone, the guest stopping the output for 0.3 s so the + /// host stream runs dry, then starting it again (see + /// [`a_tone_survives_a_pause`]). The 512-pair ring holds five and ten + /// whole cycles, so the tones are 468.75 and 937.5 Hz rather than 440 + /// and 880. + struct O2 { + a: MaceAudio, + ram: O2Memory, + } + + const O2_RING_BASE: u32 = 0x0010_0000; + const O2_TONE: (f64, f64) = (5.0 * 48000.0 / 512.0, 10.0 * 48000.0 / 512.0); + + impl CardUnderTest for O2 { + const NAME: &'static str = "o2-underrun"; + const PAUSE_IS_STALL: bool = false; + fn build(cfg: &AudioConfig) -> Self { + let ram = O2Memory::single(8 << 20); + let a = MaceAudio::new(); + a.enable_output(cfg.clone()); + a.write(MACE_AUDIO, 0); + write_codec(&a, 28, 0x0800); + write_codec(&a, 17, 48000); + write_codec(&a, 15, 1 << 8); + write_codec(&a, 27, 1 << 8); + write_codec(&a, 9, 0x0808); + for (i, &v) in tones(512, 48000, O2_TONE.0, O2_TONE.1, 16000.0).iter().enumerate() { + let o = ram.dma_offset(O2_RING_BASE | 0x1000 | i as u32 * 4).unwrap(); + ram.put_be(o, 4, (i32::from(v) << 8) as u32); + } + Self { a, ram } } - let io = AudioIo { ram: &ram, ring_base, ust: 0 }; - // The guest keeps the ring full and the service pass plays it, on - // or off. - let run = |ms: u64| { + fn tone(&self) -> (f64, f64) { + O2_TONE + } + fn rate(&self) -> f64 { + 48000.0 + } + fn play(&self) { + self.a.write(MACE_AUDIO + 0x40, CTRL_ENABLE); + } + fn pause(&self) { + self.a.write(MACE_AUDIO + 0x40, 0); + } + /// The guest keeps the ring full and the service pass plays it, on + /// or off. + fn wait(&self, ms: u64) { + let io = AudioIo { ram: &self.ram, ring_base: O2_RING_BASE, ust: 0 }; let end = Instant::now() + std::time::Duration::from_millis(ms); while Instant::now() < end { - let rptr = a.read(MACE_AUDIO + 0x48) as u32; - a.write(MACE_AUDIO + 0x50, u64::from(rptr.wrapping_sub(BLOCK) & PTR_MASK)); - a.poll(&io); + let rptr = self.a.read(MACE_AUDIO + 0x48) as u32; + self.a.write(MACE_AUDIO + 0x50, u64::from(rptr.wrapping_sub(BLOCK) & PTR_MASK)); + self.a.poll(&io); std::thread::sleep(std::time::Duration::from_millis(2)); } - }; - let frames = || (a.msc_ust(1) >> 32) as f64; - a.write(MACE_AUDIO + 0x40, CTRL_ENABLE); - run(600); - a.write(MACE_AUDIO + 0x40, 0); - let (first, before) = (frames(), a.underruns.load(Ordering::Relaxed)); - run(300); - let (paused, underran) = (frames(), a.underruns.load(Ordering::Relaxed) - before); - a.write(MACE_AUDIO + 0x40, CTRL_ENABLE); - run(600); - a.write(MACE_AUDIO + 0x40, 0); - let second = frames() - paused; - // What the host still holds plays out. - run(300); - a.player.lock().take(); - let heard = ear.heard(); - assert_a_tone_either_side_of_a_pause(&heard, left, right, 8000, [first / 48000.0, second / 48000.0]); - assert!(underran > 0, "the host stream ran dry while the output was stopped"); + } + fn frames(&self) -> f64 { + self.a.meter.frames(1) as f64 + } + fn meter(&self) -> &Meter { + &self.a.meter + } + fn finish(&self) { + self.a.player.lock().take(); + } } #[test] - fn a_tone_survives_an_underrun_into_a_file() { - a_tone_survives_an_underrun(crate::host_audio::test_signal::Backend::File); + fn a_tone_survives_a_pause_into_a_file() { + a_tone_survives_a_pause::(crate::host_audio::test_signal::Backend::File); } #[test] - fn a_tone_survives_an_underrun_on_the_real_device() { - a_tone_survives_an_underrun(crate::host_audio::test_signal::Backend::RealDevice); + fn a_tone_survives_a_pause_on_the_real_device() { + a_tone_survives_a_pause::(crate::host_audio::test_signal::Backend::RealDevice); } } diff --git a/src/dev/rad1.rs b/src/dev/rad1.rs index 6ffe0e09e..914c1c0f6 100644 --- a/src/dev/rad1.rs +++ b/src/dev/rad1.rs @@ -77,7 +77,7 @@ use std::time::{Duration, Instant}; use crate::config::AudioConfig; use crate::dev::host_pcm::{CardClock, Sink, Wav, PCM_CHANNELS}; use crate::devlog::LogModule; -use crate::host_audio::{HostOut, Resampler}; +use crate::host_audio::{HostOut, Meter, Resampler}; use crate::hptimer::{TimerId, TimerManager, TimerReturn}; use crate::snapshot::{field, field_bool, field_u32, field_u32s, field_u64, field_u64_vec, field_u64s, field_u8, StateTable}; use crate::traits::{Device, Saveable}; @@ -261,19 +261,21 @@ struct ChanInfo { slot_ptr: u64, } +const CHAN_NAMES: [&str; NUM_CH] = ["analog in", "analog out", "AES3-input subcode"]; + const CHAN_INFO: [ChanInfo; NUM_CH] = [ ChanInfo { - name: "analog input", ring: RING_INPUT, tag: 0, frame_bytes: 8, enable_bit: ENABLE_BIT, + name: CHAN_NAMES[CH_IN], ring: RING_INPUT, tag: 0, frame_bytes: 8, enable_bit: ENABLE_BIT, output: false, clockgen: Some(0), freq: 0, pos_a: REG_POS_ANALOG_IN_A, pos_a_shift: 18, pos_b: REG_POS_ANALOG_B, pos_b_shift: 18, pos_b_parent: false, slot_ptr: SLOT_PTR_ANALOG_IN, }, ChanInfo { - name: "analog output", ring: RING_OUTPUT, tag: 1, frame_bytes: 8, enable_bit: ENABLE_BIT, + name: CHAN_NAMES[CH_OUT], ring: RING_OUTPUT, tag: 1, frame_bytes: 8, enable_bit: ENABLE_BIT, output: true, clockgen: Some(1), freq: 0, pos_a: REG_POS_ANALOG_OUT_A, pos_a_shift: 18, pos_b: REG_POS_ANALOG_B, pos_b_shift: 4, pos_b_parent: false, slot_ptr: SLOT_PTR_ANALOG_OUT, }, ChanInfo { - name: "AES3-input subcode", ring: RING_AES_SUB, tag: 6, frame_bytes: 256, + name: CHAN_NAMES[CH_AES_SUB], ring: RING_AES_SUB, tag: 6, frame_bytes: 256, enable_bit: SUBCODE_ENABLE_BIT, output: false, clockgen: None, freq: FREQ_AES_SUB, pos_a: REG_POS_AES_SUB, pos_a_shift: 4, pos_b: REG_POS_AES_SUB, pos_b_shift: 18, pos_b_parent: true, slot_ptr: SLOT_PTR_AES_SUB, }, @@ -653,10 +655,8 @@ pub struct Inner { sink: Mutex>, /// Opens the host stream; tests put their own ring behind it. open_host: fn(&Inner, &AudioConfig) -> Option, - /// Whether the host ring is full, so each run of dropped output is - /// logged once. - host_full: AtomicBool, - underruns: Arc, + /// What the analog channels have moved and the host stream has done. + meter: Arc, /// Whether 0x88 and 0x8c mute the output: the Octane's card only. mute_words: bool, /// Whether the counter at 0x30 runs from reset, with no control write: @@ -669,7 +669,7 @@ pub struct Inner { /// The host stream: 200 ms of stereo ring at the stream's rate. fn open_host_output(card: &Inner, cfg: &AudioConfig) -> Option { let ring = |rate: u32| rate as usize * 2 / 5; - crate::host_audio::open_output(cfg, card.underruns.clone(), Arc::new(AtomicBool::new(true)), ring, "Octane audio", "IRIS_OCTANE_AUDIO_CAPTURE") + crate::host_audio::open_output(cfg, card.meter.clone(), ring, "Octane audio", "IRIS_OCTANE_AUDIO_CAPTURE") } impl Deref for Inner { @@ -697,8 +697,7 @@ impl Inner { audio_cfg: Mutex::new(None), sink: Mutex::new(None), open_host: open_host_output, - host_full: AtomicBool::new(false), - underruns: Arc::new(AtomicU64::new(0)), + meter: Meter::new(if ust_free_running { "RAD1 (MediaIO)" } else { "RAD1" }, &CHAN_NAMES[..CH_AES_SUB]), mute_words: revision != RAD1_REVISION_MEDIAIO, ust_free_running, me, @@ -735,6 +734,9 @@ impl Inner { /// host audio enabled. Called with the state lock held after anything /// that can start or stop the channel. fn arm_audio(&self, s: &mut State) { + if !(s.chan[CH_OUT].running && self.armed.load(Ordering::SeqCst)) { + self.meter.stopped(); + } let want = s.chan[CH_OUT].running && self.audio_cfg.lock().is_some(); match (want, s.audio_timer) { (true, None) => { @@ -776,6 +778,7 @@ impl Inner { } TimerReturn::Continue } else { + self.meter.stopped(); s.audio_timer = None; TimerReturn::Delete } @@ -842,6 +845,7 @@ impl Inner { /// Remove both timers; they come back with [`Inner::resume`]. fn disarm(&self) { self.armed.store(false, Ordering::SeqCst); + self.meter.stopped(); let mut s = self.state.lock(); for id in [s.audio_timer.take(), s.status_timer.take()].into_iter().flatten() { if let Some(tm) = self.timers.get() { @@ -863,6 +867,15 @@ impl Inner { } *s = State::new(now, self.ust_free_running); s.status_gen = gen; + self.meter.stopped(); + } + + /// The analog channels' frames go to the meter; the subcode channel's + /// are not audio. + fn moved(&self, idx: usize, frames: u64) { + if idx != CH_AES_SUB { + self.meter.moved(idx, frames); + } } fn startup_index(off: u32) -> Option { @@ -1350,6 +1363,7 @@ impl Inner { if repeats && ring_frames != 0 && frames >= 2 * ring_frames { let skip = (frames / ring_frames - 1) * ring_frames; s.chan[idx].frames += skip; + self.moved(idx, skip); s.advance_pos(idx, skip as u32); frames -= skip; } @@ -1387,21 +1401,14 @@ impl Inner { let samples = &mut pcm[..n as usize * PCM_CHANNELS]; frames_to_pcm(buf, samples, ANALOG_WORDS); if let Some(sink) = self.sink.lock().as_mut() { - if let Some((free, size)) = sink.play(samples, s.rate(idx).rounded_hz(), s.muted()) { - let was = self.host_full.load(Ordering::Relaxed); - // Full until half the ring is free again. - let full = if was { free < size / 2 } else { free < PCM_CHANNELS }; - if full != was { - self.host_full.store(full, Ordering::Relaxed); - crate::dlog!(LogModule::Rad1, "rad1: host audio ring {}", if full { "full: the host is not taking samples, output is being dropped" } else { "draining again" }); - } - } + sink.play(samples, s.rate(idx).rounded_hz(), s.muted()); } } let c = &mut s.chan[idx]; c.offset += chunk; c.frames += n; let done = c.offset >= c.len; + self.moved(idx, n); s.advance_pos(idx, n as u32); frames -= n; if done && !s.descriptor_end(idx) { @@ -1437,6 +1444,19 @@ impl Device for Rad1 { fn stop(&self) { self.inner.pause() } fn is_running(&self) -> bool { self.inner.armed.load(Ordering::SeqCst) } fn get_clock(&self) -> u64 { 0 } + + /// The counts are as of the last pass of the output timer: a query + /// moves nothing. + fn audio_report(&self) -> Option { + let i = &self.inner; + let rates = { + let s = i.state.lock(); + [CH_IN, CH_OUT].map(|idx| s.chan[idx].running.then(|| s.rate(idx).rounded_hz())) + }; + let sink = i.sink.lock(); + let host = sink.as_ref().and_then(|sk| sk.host.as_ref()).map(|(out, _)| out); + Some(i.meter.report(&rates, host, i.audio_cfg.lock().is_some())) + } } impl PciFunction for Rad1 { diff --git a/src/dev/rad1/tests.rs b/src/dev/rad1/tests.rs index 0421da86e..be0f655b2 100644 --- a/src/dev/rad1/tests.rs +++ b/src/dev/rad1/tests.rs @@ -5,6 +5,7 @@ use super::*; use crate::dev::host_pcm::test_time::{FakeNs, TestTime}; use crate::dev::host_pcm::HOST_RETRY; +use crate::host_audio::test_signal::{a_tone_survives_a_pause, tones, CardUnderTest}; use crate::hptimer::TimerManager; use crate::pci::PciDma; use crate::traits::Device; @@ -1160,7 +1161,7 @@ fn slow_host(card: &Inner, _: &crate::config::AudioConfig) -> Option { card.fake_ns().fetch_add(300 * SEC / 1000, Ordering::Relaxed); let (p, c) = rtrb::RingBuffer::new(32_000 * 2 / 5); HOST_RING.with(|h| *h.borrow_mut() = Some(c)); - Some(HostOut::detached(32_000, p)) + Some(HostOut::detached(card.meter.clone(), 32_000, p)) } /// A slow host open is over when the machine starts, before the guest @@ -1482,7 +1483,7 @@ fn the_mediaio_card_plays_through_its_0x88_and_0x8c_writes() { r.state().connect_dma(ram.clone()); // A 44.1 kHz host stream, so the ring's samples arrive unresampled. let (p, mut host) = rtrb::RingBuffer::new(44_100); - let host_out = (HostOut::detached(44_100, p), Resampler::new(44_100, 44_100)); + let host_out = (HostOut::detached(r.meter.clone(), 44_100, p), Resampler::new(44_100, 44_100)); *r.sink.lock() = Some(Sink { host: Some(host_out), host_failed_at: None, wav: None, tap: None }); program(&r, &RING_OUTPUT, 0x10_0000, 0xffff_f008); wr(&r, 0x58, 0x2000_0001); @@ -1560,62 +1561,76 @@ fn a_tone_in_guest_memory_reaches_the_host_on_the_real_clock() { } /// RAD1 playing a tone, the guest stopping the analog output for 0.3 s so -/// the host stream runs dry, then starting it again. Both sides of the gap -/// must be the tone with each channel on its own side, as long as the ring -/// moved, and the gap must count as underruns. The 512-frame ring holds -/// five and ten whole cycles at 44.1 kHz, so the tones are about 431 and -/// 861 Hz rather than 440 and 880; the host output resamples them. -fn a_tone_survives_an_underrun(backend: crate::host_audio::test_signal::Backend) { - use crate::host_audio::test_signal::*; - let Some(ear) = Listener::new(backend, "rad1-underrun") else { return }; - let (left, right) = (5.0 * 44100.0 / 512.0, 10.0 * 44100.0 / 512.0); - let r = Rad1::new(); - r.state().config().write(4, BAR as u32); - r.state().config().write(1, PCI_COMMAND_MEMORY_ON); - let ram = Arc::new(Ram(Mutex::new(vec![0xaa; 0x40_0000]))); - r.state().connect_dma(ram.clone()); - { - let mut m = ram.0.lock().unwrap(); - for (n, f) in tones(512, 44100, left, right, 16000.0).chunks_exact(2).enumerate() { - let at = 0x10_0000 + n * 8; - m[at..at + 4].copy_from_slice(&sample_to_word(f[0]).to_le_bytes()); - m[at + 4..at + 8].copy_from_slice(&sample_to_word(f[1]).to_le_bytes()); +/// the host stream runs dry, then starting it again (see +/// [`a_tone_survives_a_pause`]). The 512-frame ring holds five and ten whole +/// cycles at 44.1 kHz, so the tones are about 431 and 861 Hz rather than 440 +/// and 880; the host output resamples them. +const OCTANE_TONE: (f64, f64) = (5.0 * 44100.0 / 512.0, 10.0 * 44100.0 / 512.0); + +struct Octane { + r: Rad1, +} + +impl CardUnderTest for Octane { + const NAME: &'static str = "rad1-underrun"; + const PAUSE_IS_STALL: bool = false; + fn build(cfg: &AudioConfig) -> Self { + let r = Rad1::new(); + r.state().config().write(4, BAR as u32); + r.state().config().write(1, PCI_COMMAND_MEMORY_ON); + let ram = Arc::new(Ram(Mutex::new(vec![0xaa; 0x40_0000]))); + r.state().connect_dma(ram.clone()); + { + let (left, right) = OCTANE_TONE; + let mut m = ram.0.lock().unwrap(); + for (n, f) in tones(512, 44100, left, right, 16000.0).chunks_exact(2).enumerate() { + let at = 0x10_0000 + n * 8; + m[at..at + 4].copy_from_slice(&sample_to_word(f[0]).to_le_bytes()); + m[at + 4..at + 8].copy_from_slice(&sample_to_word(f[1]).to_le_bytes()); + } } + r.set_timer_manager(Arc::new(TimerManager::new())); + r.enable_output(cfg.clone()); + Device::start(&r); + start_ust(&r); + program(&r, &RING_OUTPUT, 0x10_0000, 0xffff_f008); + Self { r } + } + fn tone(&self) -> (f64, f64) { + OCTANE_TONE + } + fn rate(&self) -> f64 { + 44100.0 + } + fn play(&self) { + wr(&self.r, 0x58, 0x2000_0001); + } + fn pause(&self) { + wr(&self.r, 0x58, 0x2000_0000); + } + fn wait(&self, ms: u64) { + std::thread::sleep(Duration::from_millis(ms)); + } + fn frames(&self) -> f64 { + self.r.meter.frames(1) as f64 + } + fn meter(&self) -> &crate::host_audio::Meter { + &self.r.meter + } + fn finish(&self) { + Device::stop(&self.r); + self.r.sink.lock().take(); } - r.set_timer_manager(Arc::new(TimerManager::new())); - r.enable_output(ear.cfg.clone()); - Device::start(&r); - start_ust(&r); - program(&r, &RING_OUTPUT, 0x10_0000, 0xffff_f008); - let frames = || r.state.lock().chan[CH_OUT].frames as f64; - wr(&r, 0x58, 0x2000_0001); - std::thread::sleep(Duration::from_millis(600)); - wr(&r, 0x58, 0x2000_0000); - let (first, before) = (frames(), r.underruns.load(Ordering::Relaxed)); - std::thread::sleep(Duration::from_millis(300)); - let underran = r.underruns.load(Ordering::Relaxed) - before; - // Starting the channel again counts its frames from zero. - wr(&r, 0x58, 0x2000_0001); - std::thread::sleep(Duration::from_millis(600)); - wr(&r, 0x58, 0x2000_0000); - let second = frames(); - // What the host still holds plays out. - std::thread::sleep(Duration::from_millis(300)); - Device::stop(&r); - r.sink.lock().take(); - let heard = ear.heard(); - assert_a_tone_either_side_of_a_pause(&heard, left, right, 8000, [first / 44100.0, second / 44100.0]); - assert!(underran > 0, "the host stream ran dry while the output was stopped"); } #[test] -fn a_tone_survives_an_underrun_into_a_file() { - a_tone_survives_an_underrun(crate::host_audio::test_signal::Backend::File); +fn a_tone_survives_a_pause_into_a_file() { + a_tone_survives_a_pause::(crate::host_audio::test_signal::Backend::File); } #[test] -fn a_tone_survives_an_underrun_on_the_real_device() { - a_tone_survives_an_underrun(crate::host_audio::test_signal::Backend::RealDevice); +fn a_tone_survives_a_pause_on_the_real_device() { + a_tone_survives_a_pause::(crate::host_audio::test_signal::Backend::RealDevice); } /// The MediaIO start-up writes 0x84 with 0 (and the model once dropped the @@ -1657,3 +1672,113 @@ fn the_octane_counter_waits_for_its_control_word() { at(&r, 10_000); assert_eq!(rd(&r, 0x30), a); } + +// ---- the monitor's audio status ---- + +/// The channels' frames reach the card's meter across transfers, though a +/// channel's own count restarts with each one, and `audio status` reports +/// them; a query itself moves nothing. +#[test] +fn audio_status_counts_output_frames_across_transfers() { + let (r, _ram) = dma_card(); + start_ust(&r); + program(&r, &RING_OUTPUT, 0x10_0000, 0xffff_f008); + wr(&r, 0x58, 0x2000_0001); + at(&r, 10_000_000); + rd(&r, 0x2c); // a register read brings the channel up to date + let text = r.audio_report().unwrap(); + assert_eq!( + text, + "audio: RAD1\n\ + \x20 analog in: 0 frames moved, guest rate off\n\ + \x20 analog out: 441 frames moved, guest rate 44100 Hz\n\ + \x20 host underruns: 0 frames\n\ + \x20 dropped by the host: 0 frames\n\ + \x20 host output: none (no_audio)\n" + ); + at(&r, 20_000_000); + assert_eq!(r.audio_report().unwrap(), text, "a query does not advance the card"); + wr(&r, 0x58, 0x2000_0000); + at(&r, 30_000_000); + wr(&r, 0x58, 0x2000_0001); + at(&r, 40_000_000); + rd(&r, 0x2c); + let text = r.audio_report().unwrap(); + assert!(text.contains("analog out: 1323 frames moved"), "{text}"); +} + +/// The MediaIO card names itself and the host stream it plays to. +#[test] +fn audio_status_names_the_mediaio_card_and_its_host_stream() { + let r = Rad1::mediaio(); + let (prod, _cons) = rtrb::RingBuffer::::new(64); + let out = HostOut::detached(r.meter.clone(), 48000, prod); + *r.inner.sink.lock() = Some(Sink { host: Some((out, Resampler::new(44100, 48000))), host_failed_at: None, wav: None, tap: None }); + *r.inner.audio_cfg.lock() = Some(AudioConfig::default()); + let text = r.audio_report().unwrap(); + assert!(text.starts_with("audio: RAD1 (MediaIO)\n"), "{text}"); + assert!(text.contains("host output: test at 48000 Hz, 2 channels"), "{text}"); +} + +/// A card playing to a host ring: the output channel running, its frames +/// reaching the host, and a way to count what the silence after them would +/// add to the underruns. +fn playing_card() -> (Rad1, Box u64>) { + let (r, ram) = dma_card(); + r.armed.store(true, Ordering::SeqCst); + let (prod, cons) = rtrb::RingBuffer::::new(4096); + let out = HostOut::detached(r.meter.clone(), 44100, prod); + *r.sink.lock() = Some(Sink { host: Some((out, Resampler::new(44100, 44100))), host_failed_at: None, wav: None, tap: None }); + let (meter, cons, _ram) = (r.meter.clone(), std::sync::Mutex::new(cons), ram); + // Drain what the card wrote, then let the host find one frame of silence. + let underrun = Box::new(move || { + let mut c = cons.lock().unwrap(); + let n = c.slots(); + c.read_chunk(n).unwrap().commit_all(); + crate::host_audio::count_underrun(crate::host_audio::pop_frames(&mut c, 2, &mut [0i16; 2], |v| v), &meter); + meter.underruns() + }); + assert_eq!(underrun(), 0, "idle"); + start_ust(&r); + program(&r, &RING_OUTPUT, 0x10_0000, 0xffff_f008); + wr(&r, 0x58, 0x2000_0001); + at(&r, 10_000_000); + rd(&r, 0x2c); // brings the channel up to date: frames reach the host + assert_eq!(underrun(), 1, "playing"); + (r, underrun) +} + +/// The output channel's first frame to the host starts the card playing and +/// the guest stopping the channel ends it: the host's silence counts as +/// underruns only in between. +#[test] +fn underruns_count_from_the_first_frame_until_the_channel_stops() { + let (r, underrun) = playing_card(); + wr(&r, 0x58, 0x2000_0000); + assert_eq!(underrun(), 1, "stopped"); +} + +/// A machine pause ends it too. +#[test] +fn pausing_the_machine_ends_playing() { + let (r, underrun) = playing_card(); + Device::stop(&r); + assert_eq!(underrun(), 1, "paused"); +} + +/// So does a hard reset, which replaces the channel state with no guest write. +#[test] +fn a_reset_ends_playing() { + let (r, underrun) = playing_card(); + r.inner.reset(); + assert_eq!(underrun(), 1, "reset"); +} + +/// And a channel that stops by itself, its ring gone, found by the pump. +#[test] +fn a_channel_that_stops_by_itself_ends_playing() { + let (r, underrun) = playing_card(); + r.state.lock().chan[CH_OUT].running = false; + r.inner.pump(); + assert_eq!(underrun(), 1, "stopped by the pump"); +} diff --git a/src/host_audio.rs b/src/host_audio.rs index 295f3487d..575d3ed91 100644 --- a/src/host_audio.rs +++ b/src/host_audio.rs @@ -18,6 +18,66 @@ const PREFERRED_RATES: &[u32] = &[48000, 44100, 22050]; #[cfg(target_os = "linux")] const PULSE_FRAMES: u32 = 512; +/// What a card's output has done, counted the same way for every card from +/// the start of the machine, with or without a host stream open: frames each +/// output moved, frames the host stream played as silence while the card was +/// playing, and frames the host ring refused. +pub struct Meter { + card: &'static str, + outputs: &'static [&'static str], + moved: Box<[AtomicU64]>, + underruns: AtomicU64, + dropped: AtomicU64, + /// Set by the first frame the card writes to the host ring, cleared by + /// [`Meter::stopped`]: an idle card sends nothing, so the host's silence + /// is an underrun only while it is set. + playing: AtomicBool, +} + +impl Meter { + /// A meter for `card` with `outputs`, in the order the card reports them. + /// Every card names its outputs `analog in`, `analog out` (`analog out 1` + /// and `2` for two), `S/PDIF out`, in that order, for those it has. + pub fn new(card: &'static str, outputs: &'static [&'static str]) -> Arc { + let moved = outputs.iter().map(|_| AtomicU64::new(0)).collect(); + Arc::new(Self { card, outputs, moved, underruns: AtomicU64::new(0), dropped: AtomicU64::new(0), playing: AtomicBool::new(false) }) + } + + /// `output` has moved `frames` more frames, to the host or not. + pub fn moved(&self, output: usize, frames: u64) { self.moved[output].fetch_add(frames, Ordering::Relaxed); } + /// The card has no output running, or the machine stopped. + pub fn stopped(&self) { self.playing.store(false, Ordering::Relaxed); } + /// Whether a frame has been written since the card last stopped. + pub fn playing(&self) -> bool { self.playing.load(Ordering::Relaxed) } + /// A frame has reached the host ring, or would have, with none open. + pub fn started(&self) { if !self.playing.load(Ordering::Relaxed) { self.playing.store(true, Ordering::Relaxed); } } + pub fn frames(&self, output: usize) -> u64 { self.moved[output].load(Ordering::Relaxed) } + pub fn underruns(&self) -> u64 { self.underruns.load(Ordering::Relaxed) } + pub fn dropped(&self) -> u64 { self.dropped.load(Ordering::Relaxed) } + + /// What `audio status` prints: the counts, the guest's rate for each + /// output (`rates`, `None` while off) and where the output goes. `out` is + /// the open host stream, `wanted` whether host output is on (`no_audio` + /// is not set). + pub fn report(&self, rates: &[Option], out: Option<&HostOut>, wanted: bool) -> String { + use std::fmt::Write; + let frames = |n: u64| format!("{n} frame{}", if n == 1 { "" } else { "s" }); + let mut s = format!("audio: {}\n", self.card); + for (i, (name, rate)) in self.outputs.iter().zip(rates).enumerate() { + let rate = rate.map_or("off".to_string(), |r| format!("{r} Hz")); + writeln!(s, " {name}: {} moved, guest rate {rate}", frames(self.frames(i))).unwrap(); + } + writeln!(s, " host underruns: {}\n dropped by the host: {}", frames(self.underruns()), frames(self.dropped())).unwrap(); + match (out, wanted) { + (Some(o), _) => writeln!(s, " host output: {} at {} Hz, {} channels", o.target, o.stream_rate, o.channels), + (None, true) => writeln!(s, " host output: none (not open)"), + (None, false) => writeln!(s, " host output: none (no_audio)"), + } + .unwrap(); + s + } +} + /// A host output stream: i16 stereo pairs pushed into `producer` play at /// `stream_rate`, and the stream plays silence when the ring is empty. pub struct HostOut { @@ -25,12 +85,12 @@ pub struct HostOut { /// Channels per frame in the ring and the stream: 2 unless the device /// asked for more (see [`open_output_channels`]). pub channels: usize, - pub producer: Producer, - pub underruns: Arc, - // Set once prebuffering finishes and real samples are flowing; cleared when - // the codec is disarmed/reset. Gates underrun counting so idle silence - // (stream open, nothing enabled yet) isn't reported as an underrun. - pub playing: Arc, + producer: Producer, + /// The card's counters: the stream counts underruns, [`HostOut::push`] + /// refusals. + pub meter: Arc, + /// What plays the ring: the host device and API, or the `[audio] file`. + pub target: String, // What plays the ring -- a host stream or an `[audio] file` -- dropped // with the HostOut. Neither for a detached one. _stream: Option, @@ -38,22 +98,39 @@ pub struct HostOut { } impl HostOut { + /// Push one input pair through `rs`, counting the frames the ring refused. + pub fn push(&mut self, rs: &mut Resampler, l: i16, r: i16) { + self.meter.started(); + let refused = rs.push(l, r, &mut self.producer); + if refused != 0 { + self.meter.dropped.fetch_add(refused as u64, Ordering::Relaxed); + } + } + + /// Push one whole frame, counting it if the ring refused it. + pub fn push_frame(&mut self, frame: &[i16]) { + self.meter.started(); + if !push_frame(&mut self.producer, frame) { + self.meter.dropped.fetch_add(1, Ordering::Relaxed); + } + } + /// An output with no host stream behind it: whoever holds the ring's /// consumer plays it. For tests of the devices that feed one. #[cfg(test)] - pub fn detached(stream_rate: u32, producer: Producer) -> Self { - Self::detached_channels(stream_rate, 2, producer) + pub fn detached(meter: Arc, stream_rate: u32, producer: Producer) -> Self { + Self::detached_channels(meter, stream_rate, 2, producer) } /// [`HostOut::detached`] with `channels` samples to a frame. #[cfg(test)] - pub fn detached_channels(stream_rate: u32, channels: usize, producer: Producer) -> Self { + pub fn detached_channels(meter: Arc, stream_rate: u32, channels: usize, producer: Producer) -> Self { Self { stream_rate, channels, producer, - underruns: Arc::new(AtomicU64::new(0)), - playing: Arc::new(AtomicBool::new(true)), + meter, + target: "test".to_string(), _stream: None, _file: None, } @@ -96,12 +173,12 @@ impl Resampler { /// Push one input stereo pair; emits the output pairs it completes. A /// pair the ring has no room for is dropped whole, or the channels of - /// every later pair would swap. - pub fn push(&mut self, l: i16, r: i16, prod: &mut Producer) { + /// every later pair would swap. Returns how many pairs were dropped. + pub fn push(&mut self, l: i16, r: i16, prod: &mut Producer) -> usize { if self.passthrough() { - push_frame(prod, &[l, r]); - return; + return usize::from(!push_frame(prod, &[l, r])); } + let mut dropped = 0; self.h = [self.h[1], self.h[2], self.h[3], [l as f32, r as f32]]; let out = self.out_rate as u64; while self.acc < out { @@ -110,10 +187,11 @@ impl Resampler { let v = catmull_rom(self.h[0][c], self.h[1][c], self.h[2][c], self.h[3][c], t); v.round().clamp(i16::MIN as f32, i16::MAX as f32) as i16 }); - push_frame(prod, &[l, r]); + dropped += usize::from(!push_frame(prod, &[l, r])); self.acc += self.in_rate as u64; } self.acc -= out; + dropped } } @@ -134,7 +212,7 @@ pub fn push_frame(prod: &mut Producer, frame: &[i16]) -> bool { /// each sample through `conv`. A frame the ring cannot supply whole is /// silence, and what it holds stays for the next call: an underrun in the /// middle of a frame would otherwise play the rest of the frame as zeros -/// and start the next one a channel late for good. Returns the samples +/// and start the next one a channel late for good. Returns the frames /// short. pub fn pop_frames(c: &mut Consumer, channels: usize, out: &mut [T], mut conv: impl FnMut(i16) -> T) -> usize { let mut missed = 0; @@ -150,7 +228,7 @@ pub fn pop_frames(c: &mut Consumer, channels: usize, out: &mut [T], mut } Err(_) => { frame.iter_mut().for_each(|o| *o = conv(0)); - missed += channels; + missed += 1; } } } @@ -264,13 +342,12 @@ fn output_buffer(audio: &AudioConfig, host: cpal::HostId) -> cpal::BufferSize { /// rate). The stream plays silence when the ring buffer is empty. pub fn open_output( audio: &AudioConfig, - underruns: Arc, - playing: Arc, + meter: Arc, ring_samples: impl Fn(u32) -> usize, who: &str, capture_var: &str, ) -> Option { - open_output_channels(audio, 2, underruns, playing, ring_samples, who, capture_var) + open_output_channels(audio, 2, meter, ring_samples, who, capture_var) } /// The standard speaker counts a stream is opened with: 7.1, 5.1, quad and @@ -284,13 +361,13 @@ fn open_attempts(layouts: &[u16]) -> impl Iterator + '_ { PREFERRED_RATES.iter().flat_map(move |&r| layouts.iter().map(move |&c| (c, r))) } -/// Count the samples a player had to make up with silence, once real -/// samples are flowing. +/// Count the frames a player had to make up with silence, while the card is +/// playing. #[inline] -fn count_underrun(missed: usize, playing: &AtomicBool, underruns: &AtomicU64) { - if missed > 0 && playing.load(Ordering::Relaxed) { - underruns.fetch_add(missed as u64, Ordering::Relaxed); - crate::pf_instant!(crate::perfetto::events::HAL2_UNDERRUN, underruns.load(Ordering::Relaxed)); +pub(crate) fn count_underrun(missed: usize, meter: &Meter) { + if missed > 0 && meter.playing.load(Ordering::Relaxed) { + let total = meter.underruns.fetch_add(missed as u64, Ordering::Relaxed) + missed as u64; + crate::pf_instant!(crate::perfetto::events::HOST_UNDERRUN, total); } } @@ -305,14 +382,13 @@ fn count_underrun(missed: usize, playing: &AtomicBool, underruns: &AtomicU64) { pub fn open_output_channels( audio: &AudioConfig, max_channels: usize, - underruns: Arc, - playing: Arc, + meter: Arc, ring_samples: impl Fn(u32) -> usize, who: &str, capture_var: &str, ) -> Option { if let Some(path) = &audio.file { - return open_file_output(path, underruns, playing, ring_samples, who); + return open_file_output(path, meter, ring_samples, who); } let host = output_host(audio.host); let device = host.default_output_device()?; @@ -347,8 +423,7 @@ pub fn open_output_channels( // Try f32 first (macOS CoreAudio native), then i16 (Linux ALSA). let (producer, stream) = { let (p, mut c) = RingBuffer::::new(ring_size); - let underruns_cb = underruns.clone(); - let playing_cb = playing.clone(); + let meter_cb = meter.clone(); // `capture_var`=: also write what the host plays -- the // end of the whole chain, to check or listen to offline. let mut capture = std::env::var_os(capture_var) @@ -362,18 +437,17 @@ pub fn open_output_channels( } v as f32 / 32768.0 }); - count_underrun(missed, &playing_cb, &underruns_cb); + count_underrun(missed, &meter_cb); }; match device.build_output_stream(config, data_fn, err_fn.clone(), None) { Ok(s) => (p, s), Err(_) => { // f32 failed, try i16 let (p, mut c) = RingBuffer::::new(ring_size); - let underruns_cb = underruns.clone(); - let playing_cb = playing.clone(); + let meter_cb = meter.clone(); let data_fn = move |data: &mut [i16], _: &cpal::OutputCallbackInfo| { let missed = pop_frames(&mut c, usize::from(channels), data, |v| v); - count_underrun(missed, &playing_cb, &underruns_cb); + count_underrun(missed, &meter_cb); }; match device.build_output_stream(config, data_fn, err_fn.clone(), None) { Ok(s) => (p, s), @@ -387,13 +461,14 @@ pub fn open_output_channels( }; if stream.play().is_err() { continue; } // cpal 0.18 dropped DeviceTrait::name(); a Device's Display impl is its name. - println!("{who}: audio output: {} via {:?} at {}Hz, {} channels", device, host.id(), rate, channels); + let target = format!("{device} via {:?}", host.id()); + println!("{who}: audio output: {target} at {rate}Hz, {channels} channels"); return Some(HostOut { stream_rate: rate, channels: channels as usize, producer, - underruns, - playing, + meter, + target, _stream: Some(stream), _file: None, }); @@ -490,8 +565,7 @@ impl Drop for FilePlayer { /// or a test, hear exactly what the host stream would have played. fn open_file_output( path: &Path, - underruns: Arc, - playing: Arc, + meter: Arc, ring_samples: impl Fn(u32) -> usize, who: &str, ) -> Option { @@ -506,7 +580,7 @@ fn open_file_output( let (producer, mut c) = RingBuffer::::new(ring_samples(FILE_RATE)); let stop = Arc::new(AtomicBool::new(false)); let thread = { - let (stop, underruns, playing) = (stop.clone(), underruns.clone(), playing.clone()); + let (stop, meter) = (stop.clone(), meter.clone()); let who = who.to_string(); std::thread::Builder::new().name(format!("{who} file")).spawn(move || { let start = Instant::now(); @@ -517,7 +591,7 @@ fn open_file_output( let due = (start.elapsed().as_nanos() * u128::from(FILE_RATE) / 1_000_000_000) as u64; buf.clear(); buf.resize((due - played) as usize * CHANNELS, 0); - count_underrun(pop_frames(&mut c, CHANNELS, &mut buf, |v| v), &playing, &underruns); + count_underrun(pop_frames(&mut c, CHANNELS, &mut buf, |v| v), &meter); if let Err(e) = wav.append(&buf) { eprintln!("{who}: writing the audio file failed: {e}"); return; @@ -538,8 +612,8 @@ fn open_file_output( stream_rate: FILE_RATE, channels: CHANNELS, producer, - underruns, - playing, + meter, + target: format!("file {}", path.display()), _stream: None, _file: Some(FilePlayer { stop, thread: Some(thread) }), }) @@ -948,6 +1022,77 @@ pub(crate) mod test_signal { f64::from(rate) * near.len() as f64 / near.iter().sum::() } + /// A card as the host path sees it: what the shared tone test needs of + /// each to play a known tone through its own DMA, pause it, and read what + /// it moved. + pub(crate) trait CardUnderTest: Sized { + /// Names the run's capture file. + const NAME: &'static str; + /// Whether a pause leaves the output running with nothing to play (a + /// guest that fell behind), so the host's silence is an underrun; or + /// stops the output, so it is idle and counts none. + const PAUSE_IS_STALL: bool; + /// The card, started on the real clock and playing to `cfg`, with the + /// tone in guest memory and the output not yet running. + fn build(cfg: &AudioConfig) -> Self; + /// The tone's left and right frequencies in Hz. + fn tone(&self) -> (f64, f64); + /// The rate the card plays at, in Hz. + fn rate(&self) -> f64; + /// Start, or resume, the output. + fn play(&self); + /// Pause the output, as [`CardUnderTest::PAUSE_IS_STALL`] says. + fn pause(&self); + /// Let the card run for `ms`, servicing it if it needs it. + fn wait(&self, ms: u64); + /// Frames the card has moved so far. + fn frames(&self) -> f64; + /// The card's counters. + fn meter(&self) -> &super::Meter; + /// Stop the machine and let go of the host output. + fn finish(&self); + /// Checks only this card can make of what the host heard, with the + /// frames it moved in all; `exact` when the host output is a file, + /// which holds every frame. + fn check(&self, _heard: &Heard, _moved: f64, _exact: bool) {} + } + + /// Any card playing a tone for 0.6 s, pausing for 0.3 s so the host + /// stream runs dry, then playing again. Both sides of the gap must be the + /// tone with each channel on its own side, as long as the card moved; + /// the gap counts as underruns if the pause is a stall and not if the + /// output is stopped. On an `[audio] file` this runs everywhere; on the + /// real device it checks cpal and the host's sound server too. + pub(crate) fn a_tone_survives_a_pause(backend: Backend) { + let exact = matches!(backend, Backend::File); + let Some(ear) = Listener::new(backend, C::NAME) else { return }; + let card = C::build(&ear.cfg); + let (left, right) = card.tone(); + card.play(); + card.wait(600); + card.pause(); + let (first, before) = (card.frames(), card.meter().underruns()); + card.wait(300); + let (paused, underran) = (card.frames(), card.meter().underruns() - before); + card.play(); + card.wait(600); + card.pause(); + let second = card.frames() - paused; + // What the host still holds plays out. + card.wait(300); + let rate = card.rate(); + card.finish(); + let heard = ear.heard(); + assert_a_tone_either_side_of_a_pause(&heard, left, right, 8000, [first / rate, second / rate]); + if C::PAUSE_IS_STALL { + assert!(underran > 0, "the host stream ran dry while the card had nothing to play"); + } else { + assert_eq!(underran, 0, "an output the guest stopped is idle: the host's silence is not an underrun"); + assert_eq!(paused, first, "the card moved frames while its output was stopped"); + } + card.check(&heard, first + second, exact); + } + /// Assert that `heard` holds a tone, a silence where its producer /// paused, and the tone again. The pause is the longest silence; the /// shorter ones a busy host leaves are allowed. On each side the left @@ -1059,6 +1204,59 @@ mod tests { use super::*; use super::test_signal::*; + /// A meter for a card with a running output. + fn playing_meter() -> Arc { + let m = Meter::new("test", &[]); + m.started(); + m + } + + /// The report, whatever the card: its outputs with their rates, the host + /// stream's underruns, the refusals, and where the output goes. + #[test] + fn the_report_has_one_layout_for_every_card() { + let meter = Meter::new("Example card", &["left", "right"]); + meter.moved(0, 441); + let (prod, mut cons) = RingBuffer::::new(2); + let mut out = HostOut::detached(meter.clone(), 48000, prod); + out.push_frame(&[1, 2]); + out.push_frame(&[3, 4]); + let mut missed = [0i16; 2]; + count_underrun(pop_frames(&mut cons, 2, &mut missed, |v| v), &meter); + count_underrun(pop_frames(&mut cons, 2, &mut missed, |v| v), &meter); + assert_eq!( + meter.report(&[Some(44100), None], Some(&out), true), + "audio: Example card\n\ + \x20 left: 441 frames moved, guest rate 44100 Hz\n\ + \x20 right: 0 frames moved, guest rate off\n\ + \x20 host underruns: 1 frame\n\ + \x20 dropped by the host: 1 frame\n\ + \x20 host output: test at 48000 Hz, 2 channels\n" + ); + assert!(meter.report(&[None, None], None, true).ends_with("host output: none (not open)\n")); + assert!(meter.report(&[None, None], None, false).ends_with("host output: none (no_audio)\n")); + } + + /// Silence from the host while no output runs is not an underrun. + #[test] + fn an_idle_card_counts_no_underruns() { + let meter = Meter::new("test", &[]); + let (prod, mut cons) = RingBuffer::::new(8); + let mut out = HostOut::detached(meter.clone(), 48000, prod); + let mut buf = [0i16; 8]; + count_underrun(pop_frames(&mut cons, 2, &mut buf, |v| v), &meter); + assert_eq!(meter.underruns(), 0, "idle"); + out.push_frame(&[1, 2]); + count_underrun(pop_frames(&mut cons, 2, &mut buf, |v| v), &meter); + assert_eq!(meter.underruns(), 3, "three frames short once a frame has been written"); + meter.stopped(); + count_underrun(pop_frames(&mut cons, 2, &mut buf, |v| v), &meter); + assert_eq!(meter.underruns(), 3, "stopped"); + out.push_frame(&[3, 4]); + count_underrun(pop_frames(&mut cons, 2, &mut buf, |v| v), &meter); + assert_eq!(meter.underruns(), 6, "playing again with the next frame"); + } + fn drain(c: &mut rtrb::Consumer) -> Vec { std::iter::from_fn(|| c.pop().ok()).collect() } @@ -1139,12 +1337,12 @@ mod tests { let mut out = [9i16; 12]; let missed = pop_frames(&mut c, 4, &mut out, |v| v); assert_eq!(out, [1, 2, 3, 4, 0, 0, 0, 0, 0, 0, 0, 0]); - assert_eq!(missed, 8); + assert_eq!(missed, 2, "two frames short"); // The rest of the frame arrives: it plays whole, first. p.push(7).unwrap(); p.push(8).unwrap(); let mut out = [9i16; 8]; - assert_eq!(pop_frames(&mut c, 4, &mut out, |v| v), 4); + assert_eq!(pop_frames(&mut c, 4, &mut out, |v| v), 1); assert_eq!(out, [5, 6, 7, 8, 0, 0, 0, 0]); } @@ -1168,9 +1366,9 @@ mod tests { #[test] fn a_file_output_plays_the_ring_in_real_time() { let (cfg, path) = file_config("file-output"); - let underruns = Arc::new(AtomicU64::new(0)); + let meter = playing_meter(); let start = Instant::now(); - let mut out = open_output(&cfg, underruns.clone(), Arc::new(AtomicBool::new(true)), |r| r as usize * 2, "test", "IRIS_TEST_CAPTURE") + let mut out = open_output(&cfg, meter.clone(), |r| r as usize * 2, "test", "IRIS_TEST_CAPTURE") .expect("a file output opens without a sound card"); assert_eq!(out.stream_rate, FILE_RATE, "the file rate"); // A quarter second of tone, as a device would push it. @@ -1191,7 +1389,7 @@ mod tests { assert_eq!(&played[..sent.len()], sent, "the pushed frames, unchanged and in order"); assert_tones(&played[..sent.len()], 2, FILE_RATE, 440.0, 880.0, 11000); assert!(played[sent.len()..].iter().all(|&v| v == 0), "silence once the ring is empty"); - assert!(underruns.load(Ordering::Relaxed) > 0, "the silence counted as underruns"); + assert!(meter.underruns() > 0, "the silence counted as underruns"); } /// A file that cannot be written opens no output, as a sound card that @@ -1199,7 +1397,7 @@ mod tests { #[test] fn an_unwritable_file_opens_no_output() { let cfg = AudioConfig { file: Some("/nonexistent-dir/x.wav".into()), ..AudioConfig::default() }; - assert!(open_output(&cfg, Arc::new(AtomicU64::new(0)), Arc::new(AtomicBool::new(true)), |r| r as usize, "test", "IRIS_TEST_CAPTURE").is_none()); + assert!(open_output(&cfg, playing_meter(), |r| r as usize, "test", "IRIS_TEST_CAPTURE").is_none()); } /// A card that asks for eight channels still gets a stereo file, and @@ -1207,7 +1405,7 @@ mod tests { #[test] fn a_file_output_asked_for_eight_channels_is_stereo() { let (cfg, path) = file_config("file-wide"); - let out = open_output_channels(&cfg, 8, Arc::new(AtomicU64::new(0)), Arc::new(AtomicBool::new(true)), |r| r as usize, "test", "IRIS_TEST_CAPTURE") + let out = open_output_channels(&cfg, 8, playing_meter(), |r| r as usize, "test", "IRIS_TEST_CAPTURE") .expect("a file output opens without a sound card"); assert_eq!(out.channels, 2); drop(out); @@ -1224,53 +1422,77 @@ mod tests { assert!(std::panic::catch_unwind(|| assert_tones(&swapped, 2, 48000, 440.0, 880.0, 9900)).is_err()); } - /// Frames pushed into an output as a card pushes them, in real time: a - /// 440 Hz tone on the left and 880 Hz on the right, nothing for 0.3 s so - /// the stream runs dry, then the tone again. Both sides of the gap must - /// be the tone on its own channels, as long as was pushed, and the gap - /// must count as underruns. The host end alone, with no card. - fn a_tone_survives_an_underrun(backend: Backend) { - let Some(ear) = Listener::new(backend, "host-underrun") else { return }; - let underruns = Arc::new(AtomicU64::new(0)); - let mut out = open_output(&ear.cfg, underruns.clone(), Arc::new(AtomicBool::new(true)), |r| r as usize * 2 / 5, "test", "IRIS_TEST_CAPTURE") - .expect("the output opens"); - let rate = out.stream_rate; - // One second holds whole cycles of both at any rate. - let tone = tones(rate as usize, rate, 440.0, 880.0, 16000.0); - let mut at = 0usize; - // Push what is due every 2 ms for `ms`; returns the frames pushed. - let mut play = |out: &mut HostOut, ms: u64| { + /// The host output with no card: frames pushed as a card pushes them, in + /// real time. A pause is a stall: nothing is pushed. + struct RawCard { + out: std::sync::Mutex>, + meter: Arc, + rate: u32, + tone: Vec, + at: std::sync::atomic::AtomicUsize, + pushed: AtomicU64, + running: AtomicBool, + } + + impl CardUnderTest for RawCard { + const NAME: &'static str = "host-underrun"; + const PAUSE_IS_STALL: bool = true; + fn build(cfg: &AudioConfig) -> Self { + let meter = Meter::new("test", &[]); + let out = open_output(cfg, meter.clone(), |r| r as usize * 2 / 5, "test", "IRIS_TEST_CAPTURE").expect("the output opens"); + // One second holds whole cycles of both at any rate. + let tone = tones(out.stream_rate as usize, out.stream_rate, 440.0, 880.0, 16000.0); + Self { rate: out.stream_rate, out: std::sync::Mutex::new(Some(out)), meter, tone, at: Default::default(), pushed: Default::default(), running: AtomicBool::new(false) } + } + fn tone(&self) -> (f64, f64) { + (440.0, 880.0) + } + fn rate(&self) -> f64 { + f64::from(self.rate) + } + fn play(&self) { + self.running.store(true, Ordering::Relaxed); + } + fn pause(&self) { + self.running.store(false, Ordering::Relaxed); + } + /// Push what is due every 2 ms. + fn wait(&self, ms: u64) { + let rate = self.rate() as u64; let (start, mut pushed) = (Instant::now(), 0u64); while start.elapsed() < Duration::from_millis(ms) { let due = (start.elapsed().as_nanos() * u128::from(rate) / 1_000_000_000) as u64; - while pushed < due && push_frame(&mut out.producer, &tone[at * 2..at * 2 + 2]) { - at = (at + 1) % (rate as usize); - pushed += 1; + if let Some(out) = self.out.lock().unwrap().as_mut() { + while self.running.load(Ordering::Relaxed) && pushed < due && out.producer.slots() >= 2 { + let at = self.at.load(Ordering::Relaxed); + out.push_frame(&self.tone[at * 2..at * 2 + 2]); + self.at.store((at + 1) % rate as usize, Ordering::Relaxed); + pushed += 1; + self.pushed.fetch_add(1, Ordering::Relaxed); + } } std::thread::sleep(Duration::from_millis(2)); } - pushed as f64 / f64::from(rate) - }; - let first = play(&mut out, 600); - let before = underruns.load(Ordering::Relaxed); - std::thread::sleep(Duration::from_millis(300)); - let underran = underruns.load(Ordering::Relaxed) - before; - let second = play(&mut out, 600); - // What the ring still holds plays out. - std::thread::sleep(Duration::from_millis(300)); - drop(out); - let heard = ear.heard(); - assert_a_tone_either_side_of_a_pause(&heard, 440.0, 880.0, 8000, [first, second]); - assert!(underran > 0, "the stream ran dry while nothing was pushed"); + } + fn frames(&self) -> f64 { + self.pushed.load(Ordering::Relaxed) as f64 + } + fn meter(&self) -> &Meter { + &self.meter + } + /// Let go of the output, so its file is complete. + fn finish(&self) { + self.out.lock().unwrap().take(); + } } #[test] - fn a_tone_survives_an_underrun_into_a_file() { - a_tone_survives_an_underrun(Backend::File); + fn a_tone_survives_a_pause_into_a_file() { + a_tone_survives_a_pause::(Backend::File); } #[test] - fn a_tone_survives_an_underrun_on_the_real_device() { - a_tone_survives_an_underrun(Backend::RealDevice); + fn a_tone_survives_a_pause_on_the_real_device() { + a_tone_survives_a_pause::(Backend::RealDevice); } } diff --git a/src/ip27_deskside.rs b/src/ip27_deskside.rs index 7a07dc0f0..32a016c9e 100644 --- a/src/ip27_deskside.rs +++ b/src/ip27_deskside.rs @@ -301,6 +301,7 @@ impl Deskside { pci.attach(DevFn { device: media.rad1_device, function: 0 }, rad.clone()); rad.register_locks(); io.devices.push(rad.clone()); + io.monitor.push(rad.clone()); let board = std::mem::replace(&mut io.reset, Box::new(|| {})); io.reset = Box::new(move || { board(); diff --git a/src/ip27_deskside/tests.rs b/src/ip27_deskside/tests.rs index 235b0b7e8..1383fae68 100644 --- a/src/ip27_deskside/tests.rs +++ b/src/ip27_deskside/tests.rs @@ -657,6 +657,19 @@ fn the_baseio_g_has_a_second_ioc3_and_the_audio_chip() { }); } +/// The monitor answers `audio` on the Onyx2, whose MediaIO carries the audio +/// chip, and not on the Origin 2000, which has none. +#[test] +fn the_monitor_answers_audio_status_only_where_there_is_an_audio_chip() { + big_stack(|| { + let answers = |m: &DesksideMachine| m.monitor().audio_status().starts_with("audio: RAD1 (MediaIO)\n"); + let (_dir, m) = built(ONYX2_PROFILE, "audio-cmd", 1); + assert!(answers(&m), "the Onyx2 has RAD1"); + let (_dir, m) = built(ORIGIN_2000_PROFILE, "no-audio-cmd", 1); + assert!(!answers(&m), "the Origin 2000 has no audio chip"); + }); +} + /// A SuperIO source raised on the MediaIO's IOC3 reaches Bridge input 6, and /// one raised on the board's IOC3 reaches input 4. The table row's pin is the /// only thing that sets either, and no guest reads it back from the chip. diff --git a/src/ip27_machine.rs b/src/ip27_machine.rs index f8b6219a3..4d835afa5 100644 --- a/src/ip27_machine.rs +++ b/src/ip27_machine.rs @@ -437,6 +437,12 @@ impl BusDevice for Unmodelled { } impl Ip27Machine { + /// The monitor the machine serves, for tests of what it registered. + #[cfg(test)] + pub(crate) fn monitor(&self) -> &Monitor { + &self.monitor + } + pub fn new(cfg: &MachineConfig) -> Result { cfg.validate()?; let specs = B::specs(cfg)?; diff --git a/src/ip30_machine.rs b/src/ip30_machine.rs index 5e66a5178..a1be720e4 100644 --- a/src/ip30_machine.rs +++ b/src/ip30_machine.rs @@ -657,6 +657,7 @@ impl OctaneMachine { } // `ps2 type` and friends: the keyboard and mouse from the monitor. monitor.register_device(ioc3.ps2()); + monitor.register_device(rad.clone()); #[cfg(feature = "perfetto")] { crate::perfetto::set_guest_cycles(Some(cpu.cycles_ptr())); @@ -1681,6 +1682,20 @@ mod snapshot_tests { OctaneMachine::new(&cfg).expect("an Octane") } + /// The monitor answers `audio status` on the Octane for RAD1, which the + /// machine registers with it, and says there is no host output with + /// `no_audio` set. + #[test] + fn the_monitor_answers_audio_status_with_the_rad1_card() { + std::thread::Builder::new().stack_size(64 << 20).spawn(|| { + let dir = scratch("audio-cmd"); + let prom = empty_prom(&dir); + let m = machine_with(&prom, &dir, |cfg| cfg.no_audio = true); + let text = m.monitor.audio_status(); + assert!(text.starts_with("audio: RAD1\n") && text.ends_with("host output: none (no_audio)\n"), "{text}"); + }).unwrap().join().unwrap(); + } + /// An Octane with a PCI module and shoehorns: each board's Crossbow link /// comes up and its Bridge answers on its own port, a function in each /// slot is reached by a configuration read through the processor's diff --git a/src/ip32.rs b/src/ip32.rs index 1a303d75f..4a9debb3c 100644 --- a/src/ip32.rs +++ b/src/ip32.rs @@ -827,6 +827,10 @@ impl crate::traits::Device for Ip32Bus { self.devices().iter().flat_map(|d| d.register_commands()).collect() } + fn audio_report(&self) -> Option { + self.devices().iter().find_map(|d| d.audio_report()) + } + fn execute_command(&self, cmd: &str, args: &[&str], writer: Box) -> Result<(), String> { for d in self.devices() { if d.register_commands().iter().any(|(c, _)| c == cmd) { diff --git a/src/ip32/tests.rs b/src/ip32/tests.rs index f23109c93..83722dc3b 100644 --- a/src/ip32/tests.rs +++ b/src/ip32/tests.rs @@ -982,13 +982,15 @@ fn every_device_answers_the_monitor_through_the_bus() { } let bus = Ip32Bus::new(16 << 20, vec![0u8; PROM_SIZE as usize]); let names: Vec = bus.register_commands().into_iter().map(|(c, _)| c).collect(); - for cmd in ["crime", "re", "gbe", "pci", "ust", "rtc", "maceps2", "onewire", "com0", "com1", "sdma", "audio", "mec"] { + for cmd in ["crime", "re", "gbe", "pci", "ust", "rtc", "maceps2", "onewire", "com0", "com1", "sdma", "mec"] { assert!(names.iter().any(|n| n == cmd), "{cmd} is listed: {names:?}"); let out = std::sync::Arc::new(std::sync::Mutex::new(Vec::new())); bus.execute_command(cmd, &["status"], Box::new(Sink(out.clone()))).unwrap_or_else(|e| panic!("{cmd}: {e}")); assert!(!out.lock().unwrap().is_empty(), "{cmd} status printed nothing"); } assert!(bus.execute_command("nonesuch", &[], Box::new(std::io::sink())).is_err()); + // The audio chip answers the monitor's `audio status` through the bus. + assert!(bus.audio_report().is_some_and(|r| r.starts_with("audio: MACE audio\n"))); } // ---- the physical bus keeps what it maps ---- diff --git a/src/ip32_machine.rs b/src/ip32_machine.rs index c791edc1f..89a370b31 100644 --- a/src/ip32_machine.rs +++ b/src/ip32_machine.rs @@ -553,6 +553,7 @@ impl O2Machine { /// dropped; [`Self::restart_peripherals`] lets the service thread go. pub fn stop(&mut self) { self.cpu.clone().as_device().stop(); + crate::traits::Device::stop(&self.bus.mace.audio); self.paused.store(true, Ordering::SeqCst); // The guest clock points into this machine's CPU core. #[cfg(feature = "perfetto")] diff --git a/src/ip34_machine.rs b/src/ip34_machine.rs index 88e0b9b64..bd8752c03 100644 --- a/src/ip34_machine.rs +++ b/src/ip34_machine.rs @@ -168,7 +168,7 @@ impl FuelMachine { monitor.register_device(init_devlog()); monitor.register_device(Arc::new(crate::cpu::cpu_monitor::CpuMonitor::new(vec![cpu.clone()]))); monitor.register_device(PerfMonitor::new( - cpu.running_flag(), cpu.cycles_ptr(), cpu.fasttick_count(), None, None, + cpu.running_flag(), cpu.cycles_ptr(), cpu.fasttick_count(), None, )); for device in board.monitor_devices() { monitor.register_device(device); diff --git a/src/ip35_machine.rs b/src/ip35_machine.rs index 47d83c11b..3b1ddc530 100644 --- a/src/ip35_machine.rs +++ b/src/ip35_machine.rs @@ -374,7 +374,7 @@ impl Ip35Machine { let monitor = Monitor::new(); monitor.register_device(init_devlog()); monitor.register_device(Arc::new(crate::cpu::cpu_monitor::CpuMonitor::new(units.iter().map(|u| u.cpu.clone()).collect()))); - monitor.register_device(PerfMonitor::new(first.running_flag(), first.cycles_ptr(), first.fasttick_count(), None, None)); + monitor.register_device(PerfMonitor::new(first.running_flag(), first.cycles_ptr(), first.fasttick_count(), None)); for u in &units { monitor.register_device(u.node.bedrock.physical().clone()); } diff --git a/src/ip53_machine.rs b/src/ip53_machine.rs index 1703e2da2..ec21d96ff 100644 --- a/src/ip53_machine.rs +++ b/src/ip53_machine.rs @@ -1030,7 +1030,7 @@ impl TezroBoard { /// The board's devices that take monitor commands: the physical map, the /// L1, the SCSI controller, the keyboard and mouse (`ps2 type` and /// friends) and, when one is present, the VPro (`vpro ...`) and the audio - /// controller (`ice1724 status`). + /// controller (`audio status`). pub fn monitor_devices(&self) -> Vec> { let mut devices: Vec> = vec![ self.bedrock.physical().clone(), diff --git a/src/ip53_machine/tests.rs b/src/ip53_machine/tests.rs index dc0c70ce7..397d730e5 100644 --- a/src/ip53_machine/tests.rs +++ b/src/ip53_machine/tests.rs @@ -305,6 +305,10 @@ fn the_audio_controller_is_the_only_function_behind_the_bridge_when_audio_is_on( let absent = with_audio(TezroAudio::Absent); assert!(absent.audio.is_none()); assert_eq!(behind(&absent).config_read(at, 0, 4), Some(u32::MAX)); + // The monitor has an audio report with the card, and only then. + let reports = |board: &TezroBoard| board.monitor_devices().iter().any(|d| d.audio_report().is_some()); + assert!(reports(&silent)); + assert!(!reports(&absent)); } /// PIC DMA reaches memory through Bedrock IO in naturally aligned legs, and diff --git a/src/machine.rs b/src/machine.rs index 99dae5fba..0c48768c0 100644 --- a/src/machine.rs +++ b/src/machine.rs @@ -963,7 +963,6 @@ impl Machine { cpu.cycles_ptr(), cpu.fasttick_count(), board.rex3.clone(), - hpc3.hal2().cloned(), )); let monitor = Arc::new(monitor); diff --git a/src/monitor.rs b/src/monitor.rs index 77853d555..fce9138f0 100644 --- a/src/monitor.rs +++ b/src/monitor.rs @@ -54,6 +54,12 @@ impl Monitor { self.devices.lock().push(device); } + /// What `audio status` prints. + #[cfg(test)] + pub fn audio_status(&self) -> String { + audio_status(&self.devices.lock()) + } + /// Bind `addr` and serve it on a new thread. The bind happens before /// this returns, so `bound_addr` answers at once whether this monitor /// has its port. @@ -103,6 +109,20 @@ impl Monitor { } } +/// Every audio card's report, or why there is none. No machine has two cards. +fn audio_status(devices: &[Arc]) -> String { + let reports: String = devices.iter().filter_map(|d| d.audio_report()).collect(); + if reports.is_empty() { + "No audio device.\n".to_string() + } else { + reports + } +} + +fn commands_of(devices: &[Arc]) -> Vec<(String, String)> { + devices.iter().flat_map(|d| d.register_commands()).collect() +} + fn handle_client(stream: TcpStream, devices: Arc>>>) { // Register this connection with DevLog so log output is broadcast here. // Wrap in CrlfWriter so bare \n from log messages renders as CRLF on the @@ -176,6 +196,7 @@ fn handle_client(stream: TcpStream, devices: Arc>>>) { let mut target_device: Option> = None; let mut is_help = false; + let audio = cmd == "audio" && (args.is_empty() || args == ["status"]); if cmd == "help" { is_help = true; @@ -184,12 +205,14 @@ fn handle_client(stream: TcpStream, devices: Arc>>>) { { let devs = devices.lock(); if is_help { - for dev in devs.iter() { - for (c, h) in dev.register_commands() { - let _ = writeln!(writer, "{:12} - {}", c, h); - } + let cmds = commands_of(&devs); + if !cmds.iter().any(|(c, _)| c == "audio") { + let _ = writeln!(writer, "{:12} - {}", "audio", "the audio card's frames, underruns and host output"); } - } else { + for (c, h) in cmds { + let _ = writeln!(writer, "{:12} - {}", c, h); + } + } else if !audio { for dev in devs.iter() { let cmds = dev.register_commands(); if cmds.iter().any(|(c, _)| c == cmd) { @@ -200,7 +223,9 @@ fn handle_client(stream: TcpStream, devices: Arc>>>) { } } - if !is_help { + if audio { + let _ = write!(writer, "{}", audio_status(&devices.lock())); + } else if !is_help { if let Some(dev) = target_device { let cmd_writer = Box::new(BufWriter::new(crate::net::telnet::CrlfWriter::new(stream.try_clone().unwrap()))); match dev.execute_command(cmd, args, cmd_writer) { @@ -319,6 +344,17 @@ mod tests { assert_eq!(out.matches("Unknown command").count(), 1, "{out}"); } + /// `audio status` on a machine with no audio card says so, rather than + /// calling the command unknown. + #[test] + fn audio_status_without_a_card_says_so() { + for line in [&b"audio status\n"[..], b"audio\n"] { + let out = converse(line); + assert!(out.contains("No audio device"), "{out}"); + assert!(!out.contains("Unknown command"), "{out}"); + } + } + #[test] fn shutdown_before_bind_does_not_serve() { let monitor = Arc::new(Monitor::new()); diff --git a/src/perf_monitor.rs b/src/perf_monitor.rs index 21e4d82d7..65555b570 100644 --- a/src/perf_monitor.rs +++ b/src/perf_monitor.rs @@ -4,7 +4,6 @@ use std::io::Write; use std::sync::atomic::{AtomicBool, AtomicU64, Ordering}; use std::sync::Arc; -use crate::dev::hal2::Hal2; use crate::dev::ng1::rex3::Rex3; use crate::traits::Device; @@ -20,7 +19,6 @@ pub struct PerfMonitor { cpus: Vec, fasttick: Arc, rex3: Option>, - hal2: Option>, } impl PerfMonitor { @@ -29,9 +27,8 @@ impl PerfMonitor { cycles: crate::cpu::mips_core::CyclesPtr, fasttick: Arc, rex3: Option>, - hal2: Option>, ) -> Arc { - Arc::new(Self { cpu_running, cycles, cpus: Vec::new(), fasttick, rex3, hal2 }) + Arc::new(Self { cpu_running, cycles, cpus: Vec::new(), fasttick, rex3 }) } /// As [`new`](Self::new) for a machine with several processors: the @@ -44,7 +41,7 @@ impl PerfMonitor { fasttick: Arc, ) -> Arc { assert!(!cpus.is_empty(), "a machine has a processor"); - Arc::new(Self { cpu_running, cycles: cpus[0], cpus, fasttick, rex3: None, hal2: None }) + Arc::new(Self { cpu_running, cycles: cpus[0], cpus, fasttick, rex3: None }) } } @@ -127,16 +124,6 @@ impl PerfMonitor { writeln!(writer, "REX3: not present").map_err(|e| e.to_string())?; } - if let Some(hal2) = &self.hal2 { - writeln!( - writer, - "HAL2 underruns: {} codec A: hptimer", - hal2.underrun_count(), - ).map_err(|e| e.to_string())?; - } else { - writeln!(writer, "HAL2: disabled (no_audio)").map_err(|e| e.to_string())?; - } - Ok(()) } } @@ -165,7 +152,7 @@ mod tests { #[test] fn a_one_processor_snapshot_has_no_per_processor_line() { let word = 3u64; - let m = PerfMonitor::new(Arc::new(AtomicBool::new(true)), CyclesPtr::new(&word), Arc::new(AtomicU64::new(0)), None, None); + let m = PerfMonitor::new(Arc::new(AtomicBool::new(true)), CyclesPtr::new(&word), Arc::new(AtomicU64::new(0)), None); assert!(!snapshot(&m).contains("CPU cycles")); } } diff --git a/src/perfetto/events.rs b/src/perfetto/events.rs index f574d4181..1cceacadd 100644 --- a/src/perfetto/events.rs +++ b/src/perfetto/events.rs @@ -134,8 +134,9 @@ pub static HAL2_PACE: EventDef = EventDef::new("codec A pace", cat::AUDIO).with_ /// Codecs: 0 = A (DAC), 1 = B (ADC), 2 = AES TX, 3 = AES RX. pub static HAL2_ARM: EventDef = EventDef::new("arm", cat::AUDIO).on_track("HAL2").in_group(AUDIO_GROUP).with_arg("codec<<8|ch"); pub static HAL2_DISARM: EventDef = EventDef::new("disarm", cat::AUDIO).on_track("HAL2").in_group(AUDIO_GROUP).with_arg("codec"); -/// The host audio callback found the ring empty (arg: underruns so far). -pub static HAL2_UNDERRUN: EventDef = EventDef::new("host underrun", cat::AUDIO).on_track("HAL2").in_group(AUDIO_GROUP).with_arg("total"); +/// The host audio callback found the ring empty while a card was playing, on +/// any card (arg: underruns so far). +pub static HOST_UNDERRUN: EventDef = EventDef::new("host underrun", cat::AUDIO).on_track("host audio").in_group(AUDIO_GROUP).with_arg("total"); /// Octane RAD: a continuous status DMA completion (arg: the slot written), /// and the slots the driver has not yet consumed after it. The driver warns /// "RAD thread held off" when it finds all but one of the ring's slots done. diff --git a/src/traits.rs b/src/traits.rs index 2a3ca7643..518f19de3 100644 --- a/src/traits.rs +++ b/src/traits.rs @@ -376,6 +376,12 @@ pub trait Device: Send + Sync { fn execute_command(&self, _cmd: &str, _args: &[&str], _writer: Box) -> Result<(), String> { Err("Command not found".to_string()) } + + /// An audio card's report for the monitor's `audio status` + /// (see `host_audio::Meter::report`); other devices have none. + fn audio_report(&self) -> Option { + None + } } // Compile-time asserts: BUS_* constants must equal the corresponding ExecStatus values. diff --git a/wsl/README.md b/wsl/README.md index 0ef230efd..ade615e74 100644 --- a/wsl/README.md +++ b/wsl/README.md @@ -91,7 +91,7 @@ The REX3 draw-mode JIT learns across sessions. **First boot after install is alw **Before recording:** boot IRIX once, open a GL app (`glxgears`, 4Dwm), interact for 5–10 minutes, quit cleanly. The second boot replays the saved profile and is smoother. -Monitor (telnet `127.0.0.1:8888`): `perf snapshot`, `rex jit status`, `hal2 status` (cpal underrun counter; codec A dedicated pump). +Monitor (telnet `127.0.0.1:8888`): `perf snapshot`, `rex jit status`, `audio status` (host underrun counter; codec A dedicated pump). **Profile script:** `wsl\profile.ps1` — Task Manager + monitor scrape. diff --git a/wsl/premiere-ab-checklist.ps1 b/wsl/premiere-ab-checklist.ps1 index 8ef2e74f1..acd5490c1 100644 --- a/wsl/premiere-ab-checklist.ps1 +++ b/wsl/premiere-ab-checklist.ps1 @@ -25,9 +25,9 @@ Write-Host " Note: Still slower than CLI OpenGL for heavy 3D" Write-Host "" Write-Host "Verify (telnet 127.0.0.1 8888):" -ForegroundColor Cyan -Write-Host " perf snapshot (Phase 3 aggregate: REX3, HAL2, affinity)" +Write-Host " perf snapshot (Phase 3 aggregate: REX3, affinity)" Write-Host " rex jit status" -Write-Host " hal2 status (cpal underruns should stay low; codec A uses dedicated pump thread)" +Write-Host " audio status (host underruns should stay low; codec A uses dedicated pump thread)" Write-Host "" Write-Host "Benchmark helper: wsl\profile.ps1" Write-Host "CI smoke: wsl\smoke-premiere.ps1" diff --git a/wsl/profile.ps1 b/wsl/profile.ps1 index f5227593f..ab2f3c8b1 100644 --- a/wsl/profile.ps1 +++ b/wsl/profile.ps1 @@ -49,9 +49,9 @@ if ($proc) { Write-Host "`niris.exe not running — start premiere bat first." -ForegroundColor Yellow } -Write-Host "`n--- monitor: hal2 status ---" -$hal2 = Send-Monitor "hal2 status" -Write-Host $hal2 +Write-Host "`n--- monitor: audio status ---" +$audio = Send-Monitor "audio status" +Write-Host $audio Write-Host "`n--- monitor: rex jit status ---" $rexJit = Send-Monitor "rex jit status" @@ -62,7 +62,7 @@ $perf = Send-Monitor "perf snapshot" Write-Host $perf $underruns = $null -if ($hal2 -match 'underruns?\s*[=:]\s*(\d+)') { +if ($audio -match 'underruns?\s*[=:]\s*(\d+)') { $underruns = [int]$Matches[1] } @@ -71,10 +71,10 @@ $snapshot = [ordered]@{ iris_running = [bool]$proc cpu_seconds = $cpuSec working_set_mb = $wsMb - hal2_status = $hal2 + audio_status = $audio rex_jit_status = $rexJit perf_snapshot = $perf - cpal_underruns = $underruns + host_underruns = $underruns } if ($JsonOut) { diff --git a/wsl/run-iris-premiere.bat b/wsl/run-iris-premiere.bat index 24a7d1935..1ef6416a6 100644 --- a/wsl/run-iris-premiere.bat +++ b/wsl/run-iris-premiere.bat @@ -5,6 +5,6 @@ call "%~dp0ensure-build.bat" cli if errorlevel 1 exit /b 1 echo. echo Premiere mode: iris CLI + OpenGL. Click window to grab mouse; Right Ctrl releases. -echo Monitor: telnet 127.0.0.1 8888 ^| rex jit status ^| hal2 status +echo Monitor: telnet 127.0.0.1 8888 ^| rex jit status ^| audio status echo. "target\release\iris.exe" --config irix-install\iris-windows.toml diff --git a/wsl/smoke-premiere.ps1 b/wsl/smoke-premiere.ps1 index 6839d9bdd..48fe4e047 100644 --- a/wsl/smoke-premiere.ps1 +++ b/wsl/smoke-premiere.ps1 @@ -37,15 +37,15 @@ $jsonPath = "target\release\.iris-smoke-run.json" if (Test-Path $jsonPath) { $run = Get-Content $jsonPath -Raw | ConvertFrom-Json - if ($null -ne $run.cpal_underruns -and $run.cpal_underruns -gt $MaxUnderruns) { - Write-Warning "cpal underruns $($run.cpal_underruns) > $MaxUnderruns" + if ($null -ne $run.host_underruns -and $run.host_underruns -gt $MaxUnderruns) { + Write-Warning "host underruns $($run.host_underruns) > $MaxUnderruns" } if (-not (Test-Path $BaselineJson)) { Copy-Item $jsonPath $BaselineJson Write-Host "Saved baseline: $BaselineJson" -ForegroundColor Green } else { $base = Get-Content $BaselineJson -Raw | ConvertFrom-Json - Write-Host "Baseline underruns: $($base.cpal_underruns) run: $($run.cpal_underruns)" + Write-Host "Baseline underruns: $($base.host_underruns) run: $($run.host_underruns)" } } diff --git a/wsl/verify-phase3.ps1 b/wsl/verify-phase3.ps1 index c097f870c..9ab668550 100644 --- a/wsl/verify-phase3.ps1 +++ b/wsl/verify-phase3.ps1 @@ -80,8 +80,8 @@ try { Write-Host "`n--- monitor: perf snapshot ---" -ForegroundColor Yellow Send-Monitor "perf snapshot" | Write-Host - Write-Host "`n--- monitor: hal2 status ---" -ForegroundColor Yellow - Send-Monitor "hal2 status" | Write-Host + Write-Host "`n--- monitor: audio status ---" -ForegroundColor Yellow + Send-Monitor "audio status" | Write-Host Write-Host "`n(note: headless CI skips REX3; use premiere CLI/GUI for rex jit status)" -ForegroundColor DarkGray