The Sound Was Seconds Late, and Nothing Was Slow

A phone's audio, relayed through a Linux box into a stream, slowly fell seconds behind the picture. Every stage ran in real time. Every stat said zero backlog. The cause was two clocks 0.03% apart and a pipe nobody was measuring, and the fix was not a smaller buffer. How the clues pointed at it, the two wrong fixes first, and the rate matching that ended it.

I have a second iPhone that lives at home, plugged into an old laptop, and I use it from my main phone over a stream (how that works). It worked. Then, a few minutes into a video, the sound was half a second behind the mouths on screen. Ten minutes later it was a few seconds behind.

This is the story of finding why, which took longer than it should have, because every number I looked at said nothing was wrong.

The clues

Four things were true, and they turned out to be the whole answer:

1. It got worse with time. Fine at first, then late, then later.
2. Reconnecting the stream fixed it instantly.
3. Pausing playback on the phone for a few seconds fixed it.
4. Muting and unmuting on the client did not.

It also got harder to reproduce as the week went on, which made me doubt it was real. It was.

Where the sound goes

iPhone ──USB──► qvh (Go) ──► queue (≤64 blocks) ──► pipe ──► pw-cat ──► PipeWire null sink "tracephone"
   phone clock                                                            sink's own clock
                                                                                   │ monitor
                                         client ◄── stream ◄── Opus ◄── Sunshine ◄─┘

The phone sends its audio over USB alongside the screen, 48 kHz stereo. A patched copy of qvh receives it and hands it to pw-cat, which plays it into a PipeWire null sink: a virtual sound card with no hardware behind it. Sunshine records that sink’s monitor, encodes it, and streams it.

Every stage there runs in real time. That is what made it hard.

Wrong guess 1: the recorder is falling behind

The obvious suspect was the end of the chain. If Sunshine read the sink a little slower than real time, its capture buffer would grow and the sound would lag.

I added a log line to Sunshine’s capture loop: how much was waiting when it read, and how many frames it got per ten seconds. The answer, every ten seconds for twenty minutes:

Audio capture: backlog 0 ms, read 480000 frames in 10.0025 s (47988/s), longest read 9 ms

Zero backlog. Sunshine read whatever was there as fast as it arrived. Not the recorder.

(The useful thing about that line is that it prints the raw numbers and not a verdict. “Backlog OK” would have hidden the 47,988 that mattered later.)

Wrong guess 2: a burst that never drains

qvh already had a guard: count how much audio it has written, compare with the wall-clock time since playback started, and drop blocks if it is too far ahead. That guard never fired.

Reading it closely showed a real hole. It measured what had been written, not what was waiting. Blocks waiting in qvh’s queue (up to 64 blocks of about 21 ms, so 1.4 s) were invisible to it. And once anything stalled for a moment, say pw-cat while I switched videos, the backlog that built up during the stall stayed. Input and output both run at exactly real time afterwards, so nothing ever catches up. A delay, once added, is permanent.

That explained clue 2 (reconnecting throws the queue away) and clue 3 (pausing on the phone stops the input while the output keeps eating, so the queue drains). It explained clue 4 too: muting on the client changes nothing on the server.

I gave every block its arrival time and dropped any block that had waited more than 150 ms. Better. Not fixed. A few minutes of continuous playback with no stalls at all, and the sound was late again.

The thing nobody was measuring

The backlog had moved somewhere the new guard could not see either: the pipe between qvh and pw-cat. A Linux pipe holds 64 KB by default, a third of a second of this audio, and a block is “written” the moment it lands in the pipe, however long it then waits.

Linux will tell you how many bytes are sitting in a pipe: the FIONREAD ioctl on its file descriptor. I added it to qvh’s stats line, along with the queue length and the longest wait. During continuous playback:

in the pipe 26 KB  →  … about four minutes later …  →  64 KB (full), then the queue starts to grow

The pipe filled steadily, not just in steps when something stalled. Something downstream was consuming slower than the phone was producing, every second, by a tiny amount.

Two clocks

Sunshine’s log already had the numbers, once I stopped reading it for backlog and read it for rate. Over 1,113 seconds it had recorded 53,409,600 frames from the null sink:

A null sink has no hardware, so PipeWire times it with a system timer. The phone times its audio with its own crystal. Neither is wrong; they are just different clocks, and nothing in this chain reconciled them. Real sound cards and Bluetooth stacks do this all the time, by stretching or squeezing the audio slightly. Here nobody did, so the 0.03% went into a queue.

0.03% is about a second an hour. On its own, that is slow. But it is a floor that only rises, and on top of it every stall, such as a video switch, added a step that never came back down. Together they made “a few seconds late after a few minutes of browsing videos”, and they made it harder to reproduce whenever I watched more carefully and switched less.

The fix: measure the wait, thin when it grows

Rate matching does not need a resampler. It needs a measurement and a way to remove a little audio:

• Measure the real delay in front of the player: bytes in the pipe (FIONREAD) converted to time, plus how long the current block has waited in the queue.
• Above 80 ms, drop one frame in every 256 from the block before writing it. That is 0.4%: more than ten times the drift, so the backlog always shrinks, and too little to hear on speech or music.
• Above 300 ms, drop the whole block. That handles stalls, where waiting to thin it out would take too long.

// thin drops one 4-byte frame (s16 stereo) in every n.
func thin(pcm []byte, n int) []byte {
	out := make([]byte, 0, len(pcm))
	for i := 0; i+4 <= len(pcm); i += 4 {
		if (i/4)%n == n-1 {
			continue
		}
		out = append(out, pcm[i:i+4]...)
	}
	return out
}

// before writing a block to pw-cat
delay := time.Duration(float64(pipeBytes(fd))/192000*float64(time.Second)) + time.Since(blk.at)
switch {
case delay > 300*time.Millisecond:
	continue // a stall: drop the block
case delay > 80*time.Millisecond:
	pcm = thin(pcm, 256) // drifting: catch up, inaudibly
}

Dropping single frames does put a tiny discontinuity in the waveform. At one in 256 on 48 kHz audio it is not audible on anything I have played through it; a proper resampler would be smoother and is the next step if it ever is.

After

During continuous playback the pipe now sits between 13 and 18 KB, which is 70 to 95 ms, and stays there. Thinning switches on and off as the wait crosses 80 ms; the phone’s audio arrives over USB in bursts, so it crosses often, and each time it removes a little. Over an hour of playback the worst delay in front of the player was 108 ms. The “in the pipe” number in the log is now the thing I check: under about 18 KB means no drift.

What I would do differently

• Two devices means two clocks. Any time audio leaves one device’s clock and is played on another’s, something has to match the rates. A virtual device with its own timer counts. I knew this, and still did not check for it until last.
• Measure what is waiting, not what is flowing. Every rate in this chain looked right. The backlog was in the one place with no counter. FIONREAD turned it into a number.
• Log raw values, not verdicts. The line that cracked it was written to prove the recorder innocent. Its raw frame count was the measurement of the clock.
• Take the clues literally. “Pausing on the phone fixes it, muting on the client does not” already said the delay was a queue on the server side that drains only when input stops. I treated it as a curiosity for too long.

I occasionally advise small teams on backend reliability, Go performance, and production AI systems. Learn more: /services