Conversation
… proxy clock Two distinct failure modes caused the long-standing "audio randomly goes silent" problem (briankendall#14, briankendall#19, briankendall#43, briankendall#62, PR briankendall#66): 1. coreaudiod restarts the target device's IO engine underneath our IO proc without telling us (DisplayPort/HDMI audio when the display wakes, USB audio when usbaudiod restarts, sample rate changes by other processes). The sample times it then hands us restart from zero, so the read position derived from inputOutputSampleDelta lands minutes away from the write position and the output plays silence until something resets the input data. Detect this directly: track the sample time each IO cycle should start at, on both the target device side and our own, and re-anchor the delta on any backward jump or a large forward jump. A bounded fill level check on the real ring buffer capacity remains as a last resort. 2. The proxy device's synthetic clock free-ran at a rate estimated from the target's rate scalar, with the estimate reset on every GetZeroTimeStamp call (so it often fell back to nominal) and no feedback on the resulting position error, which accumulated until the read position ran off the end of the ring buffer. Now the rate scalar is only consumed when a zero time stamp period actually elapses, only used when the HAL flags it as valid, and the period length is additionally steered by a clamped PI correction on the mean ring buffer fill error so the two clocks stay phase locked. No samples are dropped or duplicated; the correction is at most 500 ppm. GetZeroTimeStamp also now advances by however many periods have elapsed rather than at most one per call. Also fix two client-counting bugs: StartIO wiped the ring buffer for every additional client rather than only the first, and StopIO set the final frame time for every client rather than only the last, which would silence the output permanently while other clients were still playing.
The ring buffer's write pointer only advances once per input cycle, so the fill level sampled at target device cycle boundaries carries a phase dependent offset of up to one input buffer that is not a real position error. Once locked, the relative phase of the two cycles freezes at an arbitrary point, the servo "corrects" that offset, the phase wraps, the reading jumps by a buffer and the loop hunts with a limit cycle (observed as mean fill errors of exactly -256 then +96 frames with +-250 ppm swings). Measure the phase between the two clocks directly instead: project the proxy's own time line (the state behind GetZeroTimeStamp) onto the host time of each target device IO cycle and compare with the sample being read. That quantity is continuous and independent of cycle quantisation.
17bd43c to
3bf7315
Compare
|
I've only given this code a quick glance over, but so far it looks good! When I was last working on this issue I figured out one of the two causes you've identified but never got as far as fixing the synthetic clock, but it looks like you got it. I'll see about putting out a beta version to see if this successfully addresses the issue for other uses without introducing any regressions, and I'm optimistic that it will. |
|
12-day report from the machine this branch was developed on (M-series MacBook Pro, macOS 15, Dell U2723QE over DisplayPort as the proxied device, Debug build of The original symptom has not occurred once. Previously I had to switch output devices and back several times a day to restore audio, most reliably after waking from sleep. The timeline-discontinuity re-anchor is firing routinely and recovering every time. Five events today alone, e.g.: Each is the DisplayPort device's engine being restarted in place on display wake, its sample time snapping back to ~13,700 after hours of running. Under 1.0.7 each of these would have been a "silent until I toggle devices" incident, which matches the several-times-a-day rate I used to see. Audio continues through every one. Clock servo statistics (from the Debug-only status line, 5291 samples over the last 36 h): mean |correction| 0.05 ppm, max 1.2 ppm, mean phase error within ±0.2 frames, worst single reading 1.2 frames. My Dell's clock is only ~3 ppm off nominal ( Guard rails never needed: zero Happy to keep running it and report anything unusual. Thanks for turning it into a beta so quickly. |
|
Update: I've switched from my local Debug build to the official signed v1.1.0b1 beta (verified byte-identical to this branch's driver code). Confirmed working after install: proxy and target IO both running, audio routing normally. I'll report here if anything unusual shows up in the logs. |
2 participants
Fixes #14, #19, #43 and (I expect) #62. Supersedes #66; see the comparison at the end.
Summary
The "audio randomly goes silent until CoreAudio is restarted" problem is two separate bugs with the same visible result. This PR fixes both at the cause, plus two client-counting bugs found on the way, and I've verified the main one in the act on my own hardware (M-series MacBook Pro, macOS 15, Dell U2723QE over DisplayPort).
ProxyAudio: output unexpected overrunevery 5 s once brokeninputOutputSampleDeltais never recomputedRoot cause 1: the target device's time line restarts underneath us
outputDeviceIOProcreads from the ring buffer atinOutputTime->mSampleTime + inputOutputSampleDelta. The delta is computed once and only recomputed viaresetInputData(), which runs onStartIO, on target device change and on sample rate change. There is a fourth event that none of those cover: coreaudiod stopping and restarting the target device's IO engine in place, sameAudioObjectID, no property notification. It happens on display wake for HDMI/DisplayPort audio, whenusbaudiodrestarts its session for USB audio (on my machine that is every ~30 minutes), and when other processes change the device's sample rate or format. The sample times the IO proc receives then restart from zero,startFramelands minutes behind the write position,Fetch()returns silence, and becausestartFrame < mStartFramethe overrun warning never fires. It stays that way until something callsresetInputData(), which is why switching devices or changing the buffer size "fixes" it.Here it is happening with this branch installed (Debug build,
log show), audio playing, afterpmset displaysleepnowand a mouse wiggle:The device had been running for 172 s (172 s x 48 kHz = 8.26 M frames) and its sample time snapped back to 13688. Audio continued without interruption. With 1.0.7 this is the moment it goes silent. The "silent after wake" reports are the same thing with a race: the HAL restarts the proxy's IO first (which re-anchors), then the display link comes up a few seconds later and restarts the target's engine, invalidating the fresh anchor.
Fix. Track the sample time each IO cycle should start at, on both the target side (
expectedOutputSampleTimeinoutputDeviceIOProc) and our own side (lastInputFrameTime + lastInputBufferFrameSizeinDoIOOperation), and re-anchor on any backward jump or a forward jump larger thankTimelineJumpToleranceFrames. This fires on the first cycle of the new time line and needs no threshold tuning: a backward sample time is unambiguous. A bounded fill-level check against the ring's real capacity remains as a last resort and has not fired in testing.Root cause 2: the proxy clock was open-loop
GetZeroTimeStampmade each 16384-frame periodnominal x rateRatio, whererateRatiowas the mean of the target'smRateScalarsamples collected since the previous call, and the accumulator was zeroed on every call rather than on every period. When no target IO cycle had run between two calls the ratio silently fell back to 1.0, so the proxy ran at some rate between nominal and the target's real rate. The residual is tens of ppm at most, but it integrates without bound, which matches "works for hours, then distorts, then dies" and matches the observation in #19 that "when proxied device is active" mode (which resets buffers whenever audio stops) helps.Fix. Treat the proxy clock as what it is, a synthetic clock we control, and phase-lock it to the target:
kAudioTimeStampRateScalarValid) and plausible.proxySampleTimeForHostTimeNoLock). Measuring the ring buffer fill level instead does not work: the write pointer only moves once per input cycle, so the sampled fill carries a phase-dependent offset of up to one input buffer and the loop hunts (I hit that in the first iteration; it showed up as mean errors of exactly -256 and +256 frames with +-250 ppm swings).GetZeroTimeStampnow advances by however many periods have elapsed rather than at most one per call.Measured behaviour over ~5 hours, across 3 sleep/wake cycles, a monitor power cycle and the display-wake restart above: phase error within +-0.3 frames, correction within +-0.3 ppm (the Dell's clock is ~3 ppm off nominal,
target rate ratio 0.999997). The steady-state correction is small on this hardware precisely because the device is close to nominal; the point of the loop is that the residual is now bounded rather than integrated.Also fixed: client counting in StartIO/StopIO
The HAL calls
StartIO/StopIOonce per client (visible in the log asStartIO,StopIO,StartIOwithin 50 ms when playback starts).StartIOcalledresetInputData()before checking the count, wiping the ring buffer under clients that were already playing.StopIOsetinputFinalFrameTimefor every client, and nothing clears it exceptresetInputData(), so a non-final client stopping would silence the output permanently at thestartFrame >= inputFinalFrameTimeearly return. Both now act only on the first/last client.resetInputData()is called outsidestateMutexto keep the lock order consistent with the IO proc (IOMutex, then stateMutex, then getZeroTimestampMutex).Why this rather than #66
I want to be fair to #66: its instinct (re-anchor the delta) is right, and for the sudden class its check would have fired here too, one cycle later. But it is a symptom detector rather than a fix, and it leaves real gaps:
ringCapacityis passedkDevice_RingBufferSize(16384), which is the zero time stamp period, not the ring buffer's capacity (88200 frames). Harmless in practice, but it shows the check is not measuring what it says it is.clock servolog line in this PR (oneDebugMsgevery 64 periods) has proven sufficient to diagnose everything above fromlog show.Review notes
ProxyAudioDevice.h(kProxyClockGainP,kProxyClockGainI,kProxyClockMaxCorrection,kTimelineJumpToleranceFrames) with the reasoning in the comment. P gives a ~24 s time constant, I is set for a damping ratio of ~0.7.LOG_NOTICEunconditionally (they are rare and are exactly what a user should paste into a bug report). The servo status line isDEBUGonly.inputOutputSampleDelta == -1as a sentinel was replaced with an explicitinputOutputSampleDeltaValidflag;smallestFramesToBufferEnd(debug only) was removed..gitignorechange just ignores a localbuild-debug/directory.usbaudiodsession restarts visible in my logs are the same in-place engine restart and should be caught by the same check; a report from someone with a USB interface (e.g. the Scarlett in fix: auto-recover from audio cutout caused by stale inputOutputSampleDelta #66) would be welcome.To verify on any machine after installing a Debug build:
A
discontinuity ... re-anchoringline with audio continuing is the fix catching the old failure;out of rangeoroverrunlines would be something new.