Files
yellowjacket/backend/player/buffered_streamer.go
T
logan 842fe47e9e
CI / check (push) Skipped
CI / e2e (push) Skipped
CI / check (pull_request) Successful in 2m38s
CI / e2e (pull_request) Successful in 9m36s
feat(player): count what the ring buffer misses
An underrun is audible and nothing counted it. When the ring is empty
BufferedStreamer.Stream zeroes the caller's buffer and returns ok, so a
run of zeros is spliced into the waveform and the step discontinuity at
each edge is a click; a series of short ones is static. That is the one
candidate in #135 whose audible signature matches the report.

`starved` and `starvedSince` already existed, from #122's stall fix,
and could not answer this: they are a *stall* detector, reset by every
arriving sample, because their job is to end a track whose source has
died and a merely slow source must not be cut short. That reset is
exactly what made the audible case invisible -- a hundred 20ms
underruns a minute never approach the give-up threshold, so they were
invisible to the log, to the UI and to every tier.

UnderrunStats counts runs, calls and samples for the life of the
streamer. Runs is the number that means something audible: one episode
is one pop however many callbacks it spans, and the ratio of runs to
calls is what separates clicking from dropping out.

Three things about the reporting are deliberate.

**Counting is in Stream and reporting is not.** Stream runs on the
speaker callback's real-time deadline, so a log line there would
allocate, format and write on the exact path whose missed deadline is
the defect -- measuring by making it worse. The count is two increments
under a lock that was already held; the report is on the 1 Hz position
ticker, which only runs while playing.

**An unchanged count is not logged**, which is emitStatus' rule one
package over. A healthy player is silent, so anything in the log is
news and the line appears exactly while it is popping.

**It is Info rather than Debug.** The default level is Info and a phone
has no convenient way to set YJ_LOG_LEVEL, so a debug line here would
be a counter nobody on the affected platform could read -- which is the
shape of the bug that made #160 necessary.

underrunDelta clamps at zero because the counter belongs to the
streamer and the streamer is replaced on every track: a baseline
carried across that boundary is the previous track's total subtracted
from a fresh zero. The baseline is reset at the load as well; a
negative count in a log line reads as a broken instrument and would
discredit the measurement this exists to make.

This is the instrument, not a fix. What it measures is on the issue.
2026-08-21 16:30:32 -04:00

388 lines
11 KiB
Go
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
package player
import (
"errors"
"sync"
"time"
"github.com/gopxl/beep/v2"
)
// BufferedStreamer wraps a beep.Streamer with a goroutine-driven
// read-ahead ring buffer. It decouples the source streamer's I/O
// timing from the speaker callback's real-time deadline, preventing
// audible glitches caused by disk stalls, GC pauses, or CPU
// scheduling delays.
//
// The read-ahead goroutine continuously fills the ring buffer from
// the source. The speaker callback drains the ring buffer without
// ever touching the source directly. If the ring buffer is
// temporarily empty (read-ahead hasn't caught up), Stream returns
// silence rather than blocking or signaling end-of-stream.
type BufferedStreamer struct {
// srcMu serializes all access to the underlying source. The
// read-ahead goroutine holds it while calling source.Stream;
// callers that need to Seek the source must hold it too (via
// LockSource/UnlockSource) so the non-thread-safe decoder is
// never read and seeked concurrently.
srcMu sync.Mutex
mu sync.Mutex
source beep.Streamer
ring [][2]float64
readPos int
writPos int
count int
done bool
err error
closed chan struct{}
// starved counts consecutive Stream calls served with silence
// because the ring was empty, and starvedSince is when that run
// began. An underrun is legitimate for a moment -- that is what
// the read-ahead exists to absorb -- but it is not legitimate
// forever, and "forever" is indistinguishable from healthy
// playback everywhere above this type: the chain never ends, so
// the player stays in Playing with the button showing pause, and
// the decoder's position never moves, so the 1 Hz report pins the
// seek bar and suppresses its interpolation.
starved int
starvedSince time.Time
// underruns accumulates for the life of this streamer, where
// starved is reset by every arriving sample.
//
// The two answer different questions and only the first was being
// asked. starved is a *stall* detector: it exists to end a track
// whose source has died, so it forgets a run the moment audio
// resumes -- which is exactly the case this counts. A hundred 20ms
// underruns a minute never approach the give-up threshold and were
// invisible to the log, the UI and every test tier, while being
// audible as static: an underrun is served as a run of zeros
// spliced into the waveform, and a step discontinuity at each edge
// is what a click is.
underruns UnderrunStats
}
// UnderrunStats is what the ring buffer missed, cumulatively.
//
// Samples rather than milliseconds because this type does not know the
// sample rate -- the player does, and converts at the point of
// reporting.
type UnderrunStats struct {
// Runs is the number of *episodes*: transitions from healthy into
// starved. Calls is how many Stream calls were served with
// silence, and Samples is how much silence that was.
//
// Runs is the count that means something audible. One episode is
// one pop however many calls it spans, and the ratio of the two is
// how long the average episode was -- which is what separates
// "clicking" from "dropping out".
Runs int64
Calls int64
Samples int64
}
// The silence fill is bounded by both a duration and a run of calls,
// and it needs both.
//
// Duration alone is the real measure -- the speaker paces itself, so
// wall clock is what says whether the source has actually stopped --
// but a caller draining in a tight loop (a test, a decode-to-buffer)
// makes hundreds of calls in microseconds and would trip nothing.
// A call count alone is the opposite failure: the same tight loop
// spends the whole budget before the read-ahead goroutine has been
// scheduled once, and ends a perfectly good stream at sample zero.
//
// The duration is longer than the 2 s read-ahead it is there to
// outlast, and the count is short enough that the speaker (~200 ms a
// call) reaches it well inside that.
const (
maxStarvedDuration = 3 * time.Second
minStarvedCalls = 8
)
// errSourceStalled is returned by Err when the source stopped
// producing samples without ever reporting end-of-stream.
var errSourceStalled = errors.New(
"audio source stopped producing samples",
)
// NewBufferedStreamer creates a BufferedStreamer that pre-fills
// bufferSize samples from source via a background goroutine.
// A typical bufferSize is 2× the sample rate (~2 seconds of audio).
func NewBufferedStreamer(
source beep.Streamer,
bufferSize int,
) *BufferedStreamer {
bs := &BufferedStreamer{
source: source,
ring: make([][2]float64, bufferSize),
closed: make(chan struct{}),
}
go bs.readAhead()
return bs
}
// finish marks the stream ended, recording err as the reason when
// there is one. Every exit from readAhead goes through it: an exit
// that leaves done false strands Stream in its underrun branch,
// where it returns silence and ok forever.
func (bs *BufferedStreamer) finish(err error) {
bs.mu.Lock()
defer bs.mu.Unlock()
bs.done = true
if err != nil && bs.err == nil {
bs.err = err
}
}
// readAhead continuously reads from the source into the ring buffer
// until the source is drained, an error occurs, or Close is called.
// It always marks the stream done on the way out.
func (bs *BufferedStreamer) readAhead() {
// Temporary buffer for reading from source outside the lock.
// 512 samples per chunk keeps the critical section short.
const chunkSize = 512
tmp := make([][2]float64, chunkSize)
// Every exit marks the stream done. An exit that does not is what
// stranded Stream in its underrun branch, returning silence and ok
// for the rest of the process's life.
var exitErr error
defer func() { bs.finish(exitErr) }()
for {
// Check if closed.
select {
case <-bs.closed:
return
default:
}
bs.mu.Lock()
// Stream gave up waiting for us. Nothing downstream is
// listening any more, so filling the ring is work for nobody.
if bs.done {
bs.mu.Unlock()
return
}
space := len(bs.ring) - bs.count
if space == 0 {
// Buffer full — release lock and wait briefly.
bs.mu.Unlock()
select {
case <-bs.closed:
return
case <-time.After(1 * time.Millisecond):
}
continue
}
// Determine how many samples to request.
toRead := space
if toRead > chunkSize {
toRead = chunkSize
}
bs.mu.Unlock()
// Read from source WITHOUT holding bs.mu so disk I/O does
// not block the speaker goroutine. srcMu is held to keep
// this read from racing a concurrent source Seek.
bs.srcMu.Lock()
n, ok := bs.source.Stream(tmp[:toRead])
bs.srcMu.Unlock()
if n > 0 {
bs.mu.Lock()
for i := range n {
bs.ring[bs.writPos] = tmp[i]
bs.writPos = (bs.writPos + 1) % len(bs.ring)
}
bs.count += n
bs.mu.Unlock()
}
if !ok {
// A drained source and a failed one both land here and are
// not the same event: one is a track that ended, the other
// is a track that broke. Err is what tells them apart, and
// it is why the player must ask before treating this as a
// natural finish.
exitErr = bs.source.Err()
return
}
// If source returned 0 samples but is still ok, yield
// briefly to avoid busy-spinning.
if n == 0 {
select {
case <-bs.closed:
return
case <-time.After(1 * time.Millisecond):
}
}
}
}
// Stream copies samples from the ring buffer into the provided
// slice. If the buffer is temporarily empty but the source is not
// yet drained, it fills the output with silence and returns
// (len(samples), true) to avoid speaker underrun.
func (bs *BufferedStreamer) Stream(
samples [][2]float64,
) (int, bool) {
bs.mu.Lock()
defer bs.mu.Unlock()
if bs.count == 0 && bs.done {
return 0, false
}
if bs.count == 0 {
// The read-ahead has not caught up. Silence buys it time --
// but only for a bounded stretch, because "forever" is
// reported upward as healthy playback and there is no watchdog
// above this to notice otherwise.
if bs.starved == 0 {
bs.underruns.Runs++
}
bs.underruns.Calls++
bs.underruns.Samples += int64(len(samples))
bs.starved++
if bs.starvedSince.IsZero() {
bs.starvedSince = time.Now()
}
if bs.starved >= minStarvedCalls &&
time.Since(bs.starvedSince) > maxStarvedDuration {
bs.done = true
if bs.err == nil {
bs.err = errSourceStalled
}
return 0, false
}
for i := range samples {
samples[i] = [2]float64{}
}
return len(samples), true
}
// Samples arrived, so whatever the stall was, it is over.
bs.resetStarvationLocked()
// Copy available samples from ring buffer.
n := len(samples)
if n > bs.count {
n = bs.count
}
for i := range n {
samples[i] = bs.ring[bs.readPos]
bs.readPos = (bs.readPos + 1) % len(bs.ring)
}
bs.count -= n
return n, true
}
// Underruns returns the cumulative underrun count.
//
// It is a snapshot rather than a live view, and it is read from
// outside the audio callback: counting happens in Stream, under the
// lock it already takes, because that path has a real-time deadline
// and anything that allocates or formats on it is a cause of the
// defect it is measuring rather than a measurement of it.
func (bs *BufferedStreamer) Underruns() UnderrunStats {
bs.mu.Lock()
defer bs.mu.Unlock()
return bs.underruns
}
// Err returns any error encountered by the source streamer.
func (bs *BufferedStreamer) Err() error {
bs.mu.Lock()
defer bs.mu.Unlock()
return bs.err
}
// Flush discards all buffered samples so the next Stream call
// returns freshly-read data from the source. This must be called
// after seeking the underlying source to prevent stale pre-seek
// audio from being played back.
func (bs *BufferedStreamer) Flush() {
bs.mu.Lock()
defer bs.mu.Unlock()
bs.readPos = 0
bs.writPos = 0
bs.count = 0
// A seek empties the ring on purpose, and the refill that follows
// is exactly the stall the budget exists to tolerate. Charging it
// against a budget the previous underrun already spent would end
// the track on a seek near the end of a slow file.
bs.resetStarvationLocked()
}
// resetStarvationLocked forgets an underrun run. Must be called with
// bs.mu held.
//
// Deliberately does not touch bs.underruns: forgetting the run is what
// makes starved a stall detector, and remembering it is the whole
// point of the counter beside it.
func (bs *BufferedStreamer) resetStarvationLocked() {
bs.starved = 0
bs.starvedSince = time.Time{}
}
// LockSource blocks the read-ahead goroutine from touching the
// underlying source, giving the caller exclusive access so it can
// safely Seek the non-thread-safe decoder. Every LockSource must
// be paired with an UnlockSource.
func (bs *BufferedStreamer) LockSource() {
bs.srcMu.Lock()
}
// UnlockSource releases the exclusive source access acquired by
// LockSource, allowing the read-ahead goroutine to resume.
func (bs *BufferedStreamer) UnlockSource() {
bs.srcMu.Unlock()
}
// Close signals the read-ahead goroutine to stop. It is safe to
// call multiple times.
func (bs *BufferedStreamer) Close() {
select {
case <-bs.closed:
// Already closed.
default:
close(bs.closed)
}
}