diff --git a/dm/host/hle_audio.c b/dm/host/hle_audio.c index 40a3b7678c..1a135b6060 100644 --- a/dm/host/hle_audio.c +++ b/dm/host/hle_audio.c @@ -352,42 +352,46 @@ static void stats_drain(void) { pthread_mutex_unlock(&g_aos_lock); for (int i = 0; i < n; i++) stats_log(&reports[i]); } +// One registry tick; the caller holds g_aos_lock and reads t after taking it. +static void au_watchdog_tick(uint64_t t, uint64_t gap) { + for (int i = 0; i < AOMAX; i++) { + aout *a = g_aos[i]; if (!a || !a->au) continue; + uint64_t n = atomic_load_explicit(&a->cb_n, memory_order_relaxed); + if (a->start_phase == AU_WAIT_CALLBACK) { + if (n != a->wd_n) { + null_stop(a); + atomic_store_explicit(&a->hold_device, 0, memory_order_release); + if (a->stalled) LOG("audio #%d: AudioUnit restarted", a->id); + a->backend = BK_AU; a->start_phase = AU_IDLE; a->stalled = a->retry_ms = 0; + a->wd_n = n; a->wd_t = t; + } else if (gap > 4ull * WD_TICK_MS * 1000000) a->wd_t = t; + else if (t - a->wd_t >= 1000000000ull) { + if (!a->stalled) LOG("[RED] audio #%d: no device callback after start; continuing on the silent sink", a->id); + AudioOutputUnitStop(a->au); a->start_phase = AU_IDLE; au_retry(a, t); + } + continue; + } + if (a->backend == BK_NULL) { + if (t >= a->retry_at) au_request_start(a); + continue; + } + if (a->backend != BK_AU) continue; + if (gap > 4ull * WD_TICK_MS * 1000000 || n != a->wd_n) { + a->wd_n = n; a->wd_t = t; + } else if (t - a->wd_t > WD_STALL_MS * 1000000ull) { + LOG("[RED] audio #%d: the device has not called back for %.0f ms while playing: the silent sink stands in, retrying the AudioUnit", a->id, (t - a->wd_t) / 1e6); + AudioOutputUnitStop(a->au); a->backend = BK_NONE; null_start(a); + au_retry(a, t); + } + } +} static void *au_watchdog(void *p) { (void)p; uint64_t last = now_ns(); for (;;) { usleep(WD_TICK_MS * 1000); pthread_mutex_lock(&g_aos_lock); uint64_t t = now_ns(), gap = t - last; last = t; - for (int i = 0; i < AOMAX; i++) { - aout *a = g_aos[i]; if (!a || !a->au) continue; - uint64_t n = atomic_load_explicit(&a->cb_n, memory_order_relaxed); - if (a->start_phase == AU_WAIT_CALLBACK) { - if (n != a->wd_n) { - null_stop(a); - atomic_store_explicit(&a->hold_device, 0, memory_order_release); - if (a->stalled) LOG("audio #%d: AudioUnit restarted", a->id); - a->backend = BK_AU; a->start_phase = AU_IDLE; a->stalled = a->retry_ms = 0; - a->wd_n = n; a->wd_t = t; - } else if (gap > 4ull * WD_TICK_MS * 1000000) a->wd_t = t; - else if (t - a->wd_t >= 1000000000ull) { - if (!a->stalled) LOG("[RED] audio #%d: no device callback after start; continuing on the silent sink", a->id); - AudioOutputUnitStop(a->au); a->start_phase = AU_IDLE; au_retry(a, t); - } - continue; - } - if (a->backend == BK_NULL) { - if (t >= a->retry_at) au_request_start(a); - continue; - } - if (a->backend != BK_AU) continue; - if (gap > 4ull * WD_TICK_MS * 1000000 || n != a->wd_n) { - a->wd_n = n; a->wd_t = t; - } else if (t - a->wd_t > WD_STALL_MS * 1000000ull) { - LOG("[RED] audio #%d: the device has not called back for %.0f ms while playing: the silent sink stands in, retrying the AudioUnit", a->id, (t - a->wd_t) / 1e6); - AudioOutputUnitStop(a->au); a->backend = BK_NONE; null_start(a); - au_retry(a, t); - } - } + au_watchdog_tick(t, gap); pthread_mutex_unlock(&g_aos_lock); stats_drain(); } diff --git a/dm/host/tests/t_audio_device.c b/dm/host/tests/t_audio_device.c index a3ca2fc3b7..c82623382d 100644 --- a/dm/host/tests/t_audio_device.c +++ b/dm/host/tests/t_audio_device.c @@ -4,6 +4,10 @@ #include #include #include +#include + +static int mock_once(pthread_once_t *, void (*)(void)); +#define pthread_once mock_once static AudioComponent mock_find(AudioComponent, const AudioComponentDescription *); static OSStatus mock_new(AudioComponent, AudioComponentInstance *); @@ -28,6 +32,12 @@ static OSStatus mock_dispose(AudioComponentInstance); #define AudioUnitUninitialize mock_uninit #define AudioComponentInstanceDispose mock_dispose #include "../hle_audio.c" +#undef pthread_once +// The device is mocked, so drive its watchdog ticks too. Real scheduler delays must not +// reset the no-callback deadline while this fixture waits for a timeout it assumes is fixed. +static int mock_once(pthread_once_t *once, void (*init)(void)) { + (void)once; assert(init == au_watchdog_start); return 0; +} __thread _Atomic int dm_host_work; // defined by the graphics host in a full build static struct { @@ -144,6 +154,40 @@ static void *guest_close(void *out) { h_au_Close(out); dispatch_semaphore_signal static int signaled(dispatch_semaphore_t s, int seconds) { return dispatch_semaphore_wait(s, dispatch_time(DISPATCH_TIME_NOW, seconds * (int64_t)NSEC_PER_SEC)) == 0; } +static void wait_phase(aout *a, int phase) { + uint64_t until = now_ns() + NSEC_PER_SEC; + for (;;) { + pthread_mutex_lock(&g_aos_lock); + int ready = a->start_phase == phase; + pthread_mutex_unlock(&g_aos_lock); + if (ready) return; + assert(now_ns() < until); + usleep(1000); + } +} +static void watchdog_tick(uint64_t t, uint64_t gap) { + pthread_mutex_lock(&g_aos_lock); + // Zero selects the real clock for callback handoff, read under the same lock as the startup stamp. + au_watchdog_tick(t ? t : now_ns(), gap); + pthread_mutex_unlock(&g_aos_lock); +} +static void retry_at_deadline(aout *a) { + wait_phase(a, AU_IDLE); + pthread_mutex_lock(&g_aos_lock); + uint64_t t = a->retry_at; + assert(a->stalled && t); + pthread_mutex_unlock(&g_aos_lock); + watchdog_tick(t - 1, 50000000); + pthread_mutex_lock(&g_aos_lock); + assert(a->start_phase == AU_IDLE); + pthread_mutex_unlock(&g_aos_lock); + assert(!signaled(start_entered, 0)); + watchdog_tick(t, 1); + pthread_mutex_lock(&g_aos_lock); + assert(a->start_phase == AU_STARTING); + pthread_mutex_unlock(&g_aos_lock); + assert(signaled(start_entered, 2)); +} static void blocked_start(void *out) { start_entered = dispatch_semaphore_create(0); start_allowed = dispatch_semaphore_create(0); @@ -179,28 +223,63 @@ static void blocked_start(void *out) { dispatch_semaphore_signal(start_allowed); pthread_join(guest, NULL); until = now_ns() + NSEC_PER_SEC; - do { au_render(a, NULL, NULL, 0, 1, &bl); if (samples[0]) break; usleep(1000); } while (now_ns() < until); + do { + au_render(a, NULL, NULL, 0, 1, &bl); + watchdog_tick(0, 50000000); + if (samples[0]) break; + usleep(1000); + } while (now_ns() < until); assert(samples[0] == 1234 && samples[1] == 1234); + // Finish the long handoff buffer through the callback. The resumed silent sink gets + // a separate 10 ms buffer: its real-time pacing must not depend on virtual watchdog time. + static int16_t drained[RATE * 2]; + AudioBufferList drain = {.mNumberBuffers = 1, .mBuffers = {{2, sizeof drained, drained}}}; + au_render(a, NULL, NULL, 0, RATE, &drain); + assert(h_au_Released(out) == &next); + gbuf resumed = {pcm, sizeof pcm, sizeof pcm}; + assert(h_au_Append(out, &resumed)); dm_audio_suspend(1); assert(signaled(device_stopped, 1)); dm_audio_suspend(0); assert(signaled(start_entered, 2)); // A successful start with no callbacks keeps releasing buffers and is retried. dispatch_semaphore_signal(start_allowed); - assert(signaled(device_stopped, 3)); + wait_phase(a, AU_WAIT_CALLBACK); + pthread_mutex_lock(&g_aos_lock); + uint64_t t = a->wd_t; + pthread_mutex_unlock(&g_aos_lock); + // Late wakes deliberately restart the deadline; three seconds of them must not stop the device. + for (int i = 0; i < 12; i++) { + t += 250000000; + watchdog_tick(t, 250000000); + assert(!signaled(device_stopped, 0)); + } + // Only a full second of timely ticks without a callback stops it, exactly at the boundary. + for (int i = 0; i < 19; i++) { + t += 50000000; + watchdog_tick(t, 50000000); + assert(!signaled(device_stopped, 0)); + } + t += 49999999; watchdog_tick(t, 49999999); + assert(!signaled(device_stopped, 0)); + watchdog_tick(t + 1, 1); + assert(signaled(device_stopped, 0)); until = now_ns() + NSEC_PER_SEC; while (!(released = h_au_Released(out)) && now_ns() < until) usleep(1000); - assert(released == &next); - assert(signaled(start_entered, 3)); + assert(released == &resumed); + retry_at_deadline(a); start_result = kAudioUnitErr_FailedInitialization; dispatch_semaphore_signal(start_allowed); - assert(signaled(start_entered, 4)); + retry_at_deadline(a); // Reset while the retry blocks. The old unit stays alive until Start returns, then its replacement starts. start_result = noErr; dm_audio_reset(); assert(unit.disposals == 0); dispatch_semaphore_signal(start_allowed); - assert(signaled(device_stopped, 1) && signaled(start_entered, 2)); + assert(signaled(device_stopped, 1)); + wait_phase(a, AU_IDLE); + watchdog_tick(0, 50000000); + assert(signaled(start_entered, 2)); assert(unit.disposals == 1); // Close returns while the driver still blocks Start: it unregisters the output and leaves the unit to the start's worker, // which stops and disposes it when Start returns.