Skip to content

Commit c7919bd

Browse files
committed
A transport's priming threshold is part of the interface, and a queue that stops moving is not full
Put a wrapper between AudioOut and a queued transport -- a tee, a logger, a volume shim -- and the audio stopped after about a tenth of a second, with no exception and no message. The backpressure cap has to clear the device's priming threshold or the two mechanisms deadlock, and it read that threshold off a PRIVATE attribute by getattr with a default of 0: a wrapper that forwarded every documented part of PCMOutput still missed it, and 0 is the value that wedges. So prebuffer_bytes is a documented property on the device interface, and the two wrappers this repository ships forward it -- ChannelAdapter scaled to its own frames like queued_size, PaceOutput straight through. ChannelAdapter is not hypothetical: it is what a mono graph on a stereo device gets, and it answered 0. The second half is worth more than the first. A cap is a latency guard, not a fact about the device, so the skip is only believed while the queue is MOVING; a queue that has not fallen for eight consecutive skips gets fed on the ordinary schedule until it does, or until a second of audio is queued, which is a dead sink rather than a priming one. That also catches a device that stopped consuming for reasons nobody wrote a guard for. AudioOut.stalls counts the episodes. Proven on a real SDL device through tests/pump_probes/device.py: a wrapper forwarding the interface renders all 192000 bytes in 0.99 s with matching digests, where the measurement on the issue was 12288 bytes and a 20 s timeout; a wrapper still hiding the threshold now completes too, on the stall guard. Three planted faults, each failing only its own test. Closes #54
1 parent 4b9e895 commit c7919bd

4 files changed

Lines changed: 312 additions & 12 deletions

File tree

lib/audiodev/__init__.py

Lines changed: 51 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -534,6 +534,27 @@ def queued_size(self):
534534
"""Bytes still waiting to play or capture. Default 0."""
535535
return 0
536536

537+
@property
538+
def prebuffer_bytes(self):
539+
"""Bytes that must be queued before this device starts consuming.
540+
541+
Part of the interface, not an implementation detail, because a
542+
producer has to clear it or the two mechanisms deadlock: a freshly
543+
primed device stays paused until this many bytes are queued, while a
544+
producer that caps itself lower has already decided the queue is full
545+
enough. Each waits on the other and the audio stops without an
546+
exception (pydevices#54).
547+
548+
It used to be readable only as ``_prebuffer_bytes``, by ``getattr``
549+
with a default of 0 -- so a wrapper that forwarded every *documented*
550+
part of this interface still missed it, and 0 is the value that
551+
wedges. A wrapper forwards this the way it forwards `queued_size`.
552+
553+
0 means the device starts on the first byte, which is the honest
554+
answer for a device with no queue at all.
555+
"""
556+
return getattr(self, "_prebuffer_bytes", 0)
557+
537558
def is_active(self):
538559
"""True while PCM remains queued. Default False."""
539560
return False
@@ -912,6 +933,26 @@ def queued_size(self):
912933
return 0
913934
return inner_q * self.format.frame_size // inner_frame
914935

936+
@property
937+
def prebuffer_bytes(self):
938+
"""The inner device's threshold, in this wrapper's frames.
939+
940+
Scaled exactly like `queued_size`, and for the same reason: the
941+
producer compares the two, so they have to be counted in the same
942+
bytes. A mono graph on a stereo device writes half the bytes the
943+
wire does, and an unscaled threshold would be twice what the
944+
producer has to clear.
945+
946+
Not forwarding this at all is pydevices#54: the pump capped itself
947+
below the inner device's priming threshold, the device stayed
948+
paused, and the audio stopped after about a tenth of a second with
949+
no exception and no message.
950+
"""
951+
inner_frame = self._inner.format.frame_size
952+
if inner_frame <= 0:
953+
return 0
954+
return self._inner.prebuffer_bytes * self.format.frame_size // inner_frame
955+
915956
def is_active(self):
916957
return self._inner.is_active()
917958

@@ -1085,6 +1126,16 @@ def close(self):
10851126
def queued_size(self):
10861127
return self._inner.queued_size() + self._held
10871128

1129+
@property
1130+
def prebuffer_bytes(self):
1131+
"""The inner device's threshold, unscaled: same format either side.
1132+
1133+
Forwarded rather than inherited, for pydevices#54's reason -- a
1134+
wrapper that answers 0 here caps the producer below what the device
1135+
needs to start, and both sides wait.
1136+
"""
1137+
return self._inner.prebuffer_bytes
1138+
10881139
def is_active(self):
10891140
return self._held > 0 or self._inner.is_active()
10901141

lib/audiodev/sample_out.py

Lines changed: 74 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -170,6 +170,29 @@ def __init__(self, transport, *, chunk_ms=40, lookahead_chunks=2,
170170
# bytes-per-len(buf) unit for the current sample's get_buffer()
171171
# results; calibrated on the first pull (see _pump_locked).
172172
self._buf_len_scale = None
173+
#: How many consecutive backpressure skips with a queue that has not
174+
#: fallen before the cap stops being believed. See `_pump_locked`.
175+
#:
176+
#: Eight is a judgement about which way to be wrong, not a
177+
#: measurement. A false positive costs one chunk of extra latency;
178+
#: a false negative costs the whole stream, silently. It is set
179+
#: above the five ticks `test_backpressure_skips_pull_and_drains_
180+
#: backlog` holds a queue saturated deliberately, so an ordinary
181+
#: full queue is never mistaken for a stall and nothing that
182+
#: worked before behaves differently -- a real backlogged transport
183+
#: drains, and this only fires for one that does not.
184+
self._stall_ticks = 8
185+
#: The queued size at the last skip, how many skips have seen it not
186+
#: fall, and whether we are currently feeding past the cap. -1 means
187+
#: "not skipping".
188+
self._stall_queued = -1
189+
self._stalled = 0
190+
self._pushing = False
191+
#: How many times the pump started feeding past the cap because the
192+
#: transport had stopped consuming -- episodes, not ticks. A number
193+
#: above 0 means the sink was not draining: a wrapper that does not
194+
#: forward `prebuffer_bytes` (pydevices#54), or a device that died.
195+
self.stalls = 0
173196
# --- the audio pump, if this firmware has one --------------------
174197
# ``pump=False`` is for a caller that has a reason (a test proving
175198
# the two paths agree, a board whose peripheral someone else owns).
@@ -776,14 +799,61 @@ def _pump_locked(self):
776799
# each side waiting on the other, measured as exactly that.
777800
chunk_bytes = chunk_frames * frame_size
778801
cap = (self._lookahead_chunks + 1) * chunk_bytes
779-
prebuffer = getattr(self.transport, "_prebuffer_bytes", 0)
802+
# The PUBLIC name, because a wrapper can only forward what it can see.
803+
# `_prebuffer_bytes` stays as a fallback for a transport written
804+
# before `prebuffer_bytes` existed, but a wrapper that forwards the
805+
# documented interface now gets this right by doing nothing special.
806+
prebuffer = getattr(self.transport, "prebuffer_bytes", None)
807+
if prebuffer is None:
808+
prebuffer = getattr(self.transport, "_prebuffer_bytes", 0)
780809
if prebuffer and prebuffer + chunk_bytes > cap:
781810
cap = prebuffer + chunk_bytes
782811
queued = self.transport.queued_size()
783812
if queued > cap:
784-
self._played_frames = target_frames
785-
self.transport.service()
786-
return
813+
# The cap is a latency guard, not a fact about the device, and
814+
# believing it forever is how the audio stops in silence. A
815+
# transport that cannot say what it needs to prime gets capped
816+
# below its own threshold, stays paused, and never consumes --
817+
# so `queued` never falls and every later tick skips too.
818+
#
819+
# So the skip is only trusted while the queue is MOVING. When it
820+
# has not fallen for `_stall_ticks` consecutive skips, feed it on
821+
# the ordinary schedule instead: more bytes is exactly what a
822+
# device waiting to prime needs, and for a sink that has genuinely
823+
# stopped it is the one observable difference between "full" and
824+
# "dead". `stalls` counts the episodes, so an app can see it.
825+
#
826+
# A CHUNK a tick is not enough, and that was measured rather than
827+
# reasoned: SDL wants 96 000 B before it unpauses, which at one
828+
# 1 920 B chunk per eight ticks is sixteen seconds of trickle --
829+
# long enough that the probe ran the SDL queue out of memory
830+
# before the device ever started. Feeding the normal schedule is
831+
# bounded by `max_catchup_chunks` and primes it in about ten
832+
# ticks.
833+
if queued < self._stall_queued or self._stall_queued < 0:
834+
self._stall_queued = queued
835+
self._stalled = 0
836+
self._pushing = False
837+
else:
838+
self._stalled += 1
839+
# One second of audio queued with nothing consumed is a dead sink,
840+
# not a priming one -- no device on this bench asks for more than
841+
# that -- so stop feeding rather than filling a board's memory.
842+
# Derived from the format rather than picked, and it sits above
843+
# every priming threshold this repository ships.
844+
if queued >= int(rate) * frame_size:
845+
self._pushing = False
846+
elif self._stalled >= self._stall_ticks and not self._pushing:
847+
self._pushing = True
848+
self.stalls += 1
849+
if not self._pushing:
850+
self._played_frames = target_frames
851+
self.transport.service()
852+
return
853+
else:
854+
self._stall_queued = -1
855+
self._stalled = 0
856+
self._pushing = False
787857

788858
bytes_needed = frames_needed * frame_size
789859
pulled = 0

tests/pump_probes/device.py

Lines changed: 16 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -95,14 +95,22 @@ def __init__(self, inner):
9595
self.seen = bytearray()
9696
self.calls = 0
9797
self.short_writes = 0
98-
# AudioOut's backpressure cap reads this off the transport, and a
99-
# wrapper that hides it DEADLOCKS: the cap stays at one lookahead
100-
# (11 520 B here) while the SDL device waits for 96 000 B before it
101-
# unpauses, so each side waits for the other and the stream stops
102-
# after 12 writes. Found the hard way by this probe's first run --
103-
# the instrument planted the fault, which is also the clearest
104-
# demonstration that the guard in `_pump_locked` is load-bearing.
105-
self._prebuffer_bytes = getattr(inner, "_prebuffer_bytes", 0)
98+
99+
# AudioOut's backpressure cap has to clear this, and a wrapper that hides
100+
# it DEADLOCKS: the cap stays at one lookahead (11 520 B here) while the
101+
# SDL device waits for 96 000 B before it unpauses, so each side waits for
102+
# the other and the stream stops after 12 writes. Found the hard way by
103+
# this probe's first run -- the instrument planted the fault, and it was
104+
# filed as pydevices#54.
105+
#
106+
# It was `self._prebuffer_bytes = getattr(inner, "_prebuffer_bytes", 0)`
107+
# here: a wrapper reaching for a private attribute because the public
108+
# interface did not carry one. It does now, so this is an ordinary
109+
# forward like `queued_size` below, and a wrapper that forwards what it
110+
# is documented to forward no longer has to know why this one matters.
111+
@property
112+
def prebuffer_bytes(self):
113+
return self.inner.prebuffer_bytes
106114

107115
# -- what AudioOut asks of a transport ---------------------------------
108116
@property

tests/test_audiodev.py

Lines changed: 171 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -583,6 +583,177 @@ def queued_size(self):
583583
len(transport.data), transport._prebuffer_bytes,
584584
"pump stopped feeding a still-priming transport (deadlock)")
585585

586+
def test_a_wrapper_that_forwards_the_interface_does_not_deadlock(self):
587+
# pydevices#54. Put anything between AudioOut and a queued transport
588+
# -- a tee, a logger, a volume shim -- and the audio used to stop
589+
# after about a tenth of a second, with no exception and no message,
590+
# because the backpressure cap read the priming threshold off a
591+
# PRIVATE attribute the wrapper had no reason to know about.
592+
#
593+
# `prebuffer_bytes` is part of the interface now, so a wrapper that
594+
# forwards what it is documented to forward gets this right without
595+
# knowing why it matters.
596+
class PrimingTransport(FakePCMOutput):
597+
_prebuffer_bytes = 4000
598+
599+
def queued_size(self):
600+
return len(self.data) # priming: nothing consumed yet
601+
602+
class Wrapper:
603+
"""Forwards the documented PCMOutput interface and nothing else."""
604+
605+
def __init__(self, inner):
606+
self.inner = inner
607+
608+
format = property(lambda self: self.inner.format)
609+
codec = property(lambda self: self.inner.codec)
610+
volume = property(lambda self: self.inner.volume)
611+
muted = property(lambda self: self.inner.muted)
612+
prebuffer_bytes = property(lambda self: self.inner.prebuffer_bytes)
613+
614+
def set_volume(self, percent):
615+
return self.inner.set_volume(percent)
616+
617+
def mute(self, value=True):
618+
return self.inner.mute(value)
619+
620+
def open(self):
621+
return self.inner.open()
622+
623+
def close(self):
624+
return self.inner.close()
625+
626+
def service(self):
627+
return self.inner.service()
628+
629+
def queued_size(self):
630+
return self.inner.queued_size()
631+
632+
def write(self, buf):
633+
return self.inner.write(buf)
634+
635+
inner = PrimingTransport(self.fmt)
636+
out = self.sample_out.AudioOut(Wrapper(inner), chunk_ms=40,
637+
lookahead_chunks=2)
638+
out.play(FakeSample([bytes(200) for _ in range(200)]))
639+
for _ in range(10):
640+
self.clock.advance(40)
641+
out.service()
642+
self.assertGreater(
643+
len(inner.data), inner._prebuffer_bytes,
644+
"a wrapper forwarding the whole interface still deadlocked")
645+
self.assertEqual(0, out.stalls,
646+
"it should not have needed the stall guard")
647+
648+
def test_a_transport_that_stops_consuming_is_pushed_past_the_cap(self):
649+
# The other half of pydevices#54, and the more valuable one: a cap is
650+
# a latency guard, not a fact about the device. A wrapper that cannot
651+
# say what it needs to prime -- every wrapper written before
652+
# `prebuffer_bytes` existed -- still caps below the threshold and
653+
# still wedges. So the skip is only believed while the queue is
654+
# MOVING, and a queue that has not fallen for `_stall_ticks` skips
655+
# gets fed anyway. That also catches a sink that has died for reasons
656+
# nobody wrote a guard for, which is the same observable signature.
657+
class PrimingTransport(FakePCMOutput):
658+
_prebuffer_bytes = 4000
659+
660+
def queued_size(self):
661+
return len(self.data)
662+
663+
class Deaf:
664+
"""A wrapper that hides the threshold: the old, naive shape."""
665+
666+
def __init__(self, inner):
667+
self.inner = inner
668+
669+
format = property(lambda self: self.inner.format)
670+
codec = property(lambda self: self.inner.codec)
671+
volume = property(lambda self: self.inner.volume)
672+
muted = property(lambda self: self.inner.muted)
673+
674+
def set_volume(self, percent):
675+
return self.inner.set_volume(percent)
676+
677+
def mute(self, value=True):
678+
return self.inner.mute(value)
679+
680+
def open(self):
681+
return self.inner.open()
682+
683+
def close(self):
684+
return self.inner.close()
685+
686+
def service(self):
687+
return self.inner.service()
688+
689+
def queued_size(self):
690+
return self.inner.queued_size()
691+
692+
def write(self, buf):
693+
return self.inner.write(buf)
694+
695+
inner = PrimingTransport(self.fmt)
696+
out = self.sample_out.AudioOut(Deaf(inner), chunk_ms=40,
697+
lookahead_chunks=2)
698+
out.play(FakeSample([bytes(200) for _ in range(200)]))
699+
wedged = len(inner.data)
700+
for _ in range(30):
701+
self.clock.advance(40)
702+
out.service()
703+
self.assertGreater(out.stalls, 0,
704+
"the pump never noticed the queue had stopped")
705+
self.assertGreater(
706+
len(inner.data), wedged,
707+
"a transport that stopped consuming was never fed again")
708+
self.assertGreater(
709+
len(inner.data), inner._prebuffer_bytes,
710+
"the stall guard did not push it past its priming threshold")
711+
712+
def test_the_stall_guard_leaves_a_draining_queue_alone(self):
713+
# The control. A suite of only failures proves a guard always fires:
714+
# a transport whose queue actually falls must never be pushed past
715+
# the cap, however long it stays above it.
716+
class Draining(FakePCMOutput):
717+
def __init__(self, fmt):
718+
super().__init__(fmt)
719+
self.backlog = 20000
720+
721+
def queued_size(self):
722+
return self.backlog
723+
724+
def service(self):
725+
self.backlog -= 200 # a real device consumes
726+
727+
transport = Draining(self.fmt)
728+
out = self.sample_out.AudioOut(transport, chunk_ms=40,
729+
lookahead_chunks=2)
730+
out.play(FakeSample([bytes(200) for _ in range(200)]))
731+
written = len(transport.data)
732+
for _ in range(30):
733+
self.clock.advance(40)
734+
out.service()
735+
self.assertEqual(0, out.stalls,
736+
"a draining queue was mistaken for a stalled one")
737+
self.assertEqual(written, len(transport.data),
738+
"the pump pulled against a draining backlog")
739+
740+
def test_channel_adapter_forwards_the_priming_threshold(self):
741+
# `ChannelAdapter` is not hypothetical: this repository ships it and
742+
# calls it "the producer-facing PCMOutput". It is what a mono graph
743+
# on a stereo device gets, and before pydevices#54 it answered 0.
744+
stereo = AudioFormat(rate=48000, channels=2, bits=16)
745+
mono = AudioFormat(rate=48000, channels=1, bits=16)
746+
747+
class PrimingTransport(FakePCMOutput):
748+
_prebuffer_bytes = 4000
749+
750+
inner = PrimingTransport(stereo)
751+
adapter = audiodev.adapt_channels(inner, mono)
752+
self.assertIsNot(adapter, inner, "no wrapper was built at all")
753+
# Counted in the wrapper's own frames, like queued_size: a mono
754+
# writer needs half the bytes to fill the same wire.
755+
self.assertEqual(2000, adapter.prebuffer_bytes)
756+
586757
def test_attach_callback_tolerates_timer_arg(self):
587758
# appdev.App._dispatch_tick always calls a subscribed callback with
588759
# one positional arg (the timer object) -- attach() must adapt

0 commit comments

Comments
 (0)