Skip to content

Commit c23a305

Browse files
committed
The pump does not fail to start; it finishes first, and the guard said the wrong thing
#52, and the answer is not the one the issue expected. `timeout_ms=200` on `audiopump.spawn()` is `sink_timeout_ms` -- how long a sink WRITE may block. It is not a start deadline, and there is no start deadline: `thread_start` either succeeds or raises. `audiopump_live` is set on the CALLING thread before spawn returns, so the comment in `RingDriver.spawn` was right and the code under it was not. `running()` is `live && !finished`, so what a bare `not mod.running()` can catch is a pump that has already FINISHED -- and under load that is exactly what it caught. The status block at the moment of the loss, measured under seven busy loops sharing one core: blocks 1 bytes 9600 error 3 ("the source ran out") fault 0 The pump started, pulled the entire 0.05 s sample, reached the end of the source and left the loop before the interpreter got its next slice. The guard called that "the pump would not start" and fell back to the interpreter thread. Three sessions' worth of looking at thread creation was looking in the wrong place. `_why_not_running()` reads the status instead of the clock, so the sentence now names what happened -- "the pump had already finished", or the real fault or error when there is one. A `StartFailed` of its own separates "this afternoon's CPU" from "this graph cannot be pumped", and `note_fault` takes `blocking=` so a transient loss is recorded without closing the door. That last one is the issue's "make the loss recoverable", and it closes the only path that still latched: `sample_out.py`'s outer `except`, which nothing cleared. (Every other refusal already recovers -- `_play` tears down when no client is left, and the teardown is what clears the block, from #45.) **The race itself is still here, and the obvious fix is not, on purpose.** Accepting the finished pump instead of tearing it down was written and measured, ten runs each under identical contention: before pump taken 96-100 of 100 (mean 98.9) audio 100/100 always accepting it pump taken 99-100 of 100 (mean 99.7) audio 99/100 in 3 runs of 10 It takes the pump more often and loses a whole round's audio two or three times in ten. Slower and always sounding beats faster and sometimes silent, so the accept is left out and the lost round is written up rather than shipped. Proved with the issue's own pinning: `tests/pump_probes/lifecycle.py cycles` under `taskset -c 0` with seven busy loops, ten runs, 100/100 rounds produced audio in every one. The full pump suite, 67 tests, OK.
1 parent ee0efd8 commit c23a305

2 files changed

Lines changed: 88 additions & 6 deletions

File tree

lib/audiodev/pump.py

Lines changed: 78 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,53 @@
8080
4: "a read that would have raised inside the pull",
8181
}
8282

83+
#: `_ERRORS` code 3. Not a failure: it is the loop saying the graph ended,
84+
#: which is what a short sample does the moment it has been pulled.
85+
_ERROR_SOURCE_RAN_OUT = 3
86+
87+
88+
class StartFailed(RuntimeError):
89+
"""The pump did not take a graph THIS TIME.
90+
91+
Separate from every other refusal on purpose. "This build cannot pump a
92+
file-backed source" is a property of the graph and will be true again in a
93+
millisecond; "the thread lost a race with a busy CPU" is a property of the
94+
afternoon, and making the second one sticky turns a transient loss into a
95+
process that never uses the pump again (pydevices#52).
96+
"""
97+
98+
99+
def _why_not_running(mod, status):
100+
"""Why a just-spawned pump is not running, as a sentence, or None.
101+
102+
**"Not running" is not the same as "did not start", and the difference is
103+
the whole of pydevices#52.** `audiopump.running()` is
104+
`live && !finished`, and `live` is set on the CALLING thread before
105+
`spawn()` returns -- so what this can catch is a pump that has already
106+
*finished*. Under load that is exactly what happens: a 0.05 s RawSample is
107+
one block, and the pump thread can pull it, reach the end of the source
108+
and leave the loop before the interpreter is scheduled again. Measured
109+
2026-09-22 under seven busy loops sharing one core: `blocks 1, bytes 9600,
110+
error 3` -- the pump did the entire job, and the check called it a failure
111+
and fell back to the interpreter thread.
112+
113+
So ask the status block rather than the clock. A fault or a real error is
114+
a failure; a loop that pulled something, or that ran out of source, did
115+
its job; only a pump that left no trace at all never started.
116+
"""
117+
import struct
118+
119+
w = struct.unpack("<%dQ" % mod.STATUS_WORDS, status)
120+
blocks, error, fault = w[0], w[5], w[24]
121+
if fault:
122+
return _FAULTS.get(fault) or "the pump faulted (%d)" % fault
123+
if error and error != _ERROR_SOURCE_RAN_OUT:
124+
return _ERRORS.get(error) or "the pump stopped (error %d)" % error
125+
if blocks or error == _ERROR_SOURCE_RAN_OUT:
126+
return None
127+
return "the pump would not start"
128+
129+
83130
# Sources that read through the VFS or a stream inside get_buffer(). The pump
84131
# refuses them by type name in C (spawn() raises); the same names are here so
85132
# a caller can ask *before* it builds anything, and so AudioOut knows to put a
@@ -636,10 +683,29 @@ def spawn(self, sample, status, loop=False):
636683
# live" flag on THIS thread before it returns, so running() is
637684
# already True and the first produce() cannot mistake a pump that
638685
# has not finished its first block for a dead one.
686+
#
687+
# What running() CAN report here is a pump that has already
688+
# finished, and a short sample under load does that before the
689+
# interpreter gets its next slice. Asking it as a bare boolean
690+
# read that as "would not start" and threw away a pump that had
691+
# just done the whole job (pydevices#52), so ask the status.
639692
self._parked = False
640693
if not mod.running():
694+
# It did not fail to start. It started, and it has already
695+
# FINISHED -- read the status before falling back, because
696+
# "the pump would not start" was the wrong sentence and sent
697+
# three sessions looking at thread creation (pydevices#52).
698+
#
699+
# Accepting the finished pump instead of tearing it down was
700+
# tried and is NOT here: it lifts "took the pump" from 98.9 to
701+
# 99.7 out of 100 under load, and costs a whole round's audio
702+
# two or three times in ten runs. Falling back to the
703+
# interpreter thread is slower and always sounds, which is the
704+
# better trade until the lost round is understood. The
705+
# measurements are on the issue.
641706
mod.shutdown()
642-
raise RuntimeError("the pump would not start")
707+
raise StartFailed(_why_not_running(mod, status)
708+
or "the pump had already finished")
643709
return
644710
# No back-pressure on this build: the pump would free-run and drop, so
645711
# it runs only inside produce(). park() returns True once the thread is
@@ -649,7 +715,7 @@ def spawn(self, sample, status, loop=False):
649715
# play-stop cycles.
650716
if not mod.park(200000):
651717
mod.shutdown()
652-
raise RuntimeError("the pump would not start")
718+
raise StartFailed("the pump would not start")
653719
self._parked = True
654720

655721
def dropped(self):
@@ -1399,10 +1465,18 @@ def _note(self, exc):
13991465
self._refusal = exc
14001466
self._blocked = True
14011467

1402-
def note_fault(self, why):
1468+
def note_fault(self, why, blocking=True):
1469+
"""Record a refusal somebody else caught.
1470+
1471+
`blocking=False` records it WITHOUT closing the door: the sentence is
1472+
on `fault()` for whoever reports it, and the next `play()` tries
1473+
again. That is what a transient loss wants -- a pump that lost one
1474+
race with a busy CPU is not a pump that cannot pump this graph, and
1475+
nothing else ever clears `_blocked` on this path (pydevices#52).
1476+
"""
14031477
self._fault = why
14041478
self._refusal = None
1405-
self._blocked = True
1479+
self._blocked = bool(blocking)
14061480

14071481
def shutdown(self):
14081482
_enter()

lib/audiodev/sample_out.py

Lines changed: 10 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -406,9 +406,17 @@ def _attach_pump(self, sample):
406406
return
407407
except Exception as exc: # noqa: BLE001 - reported, not raised
408408
self._release_prefetch()
409-
engine.note_fault(str(exc))
409+
# A transient loss must not become permanent. Nothing clears
410+
# `_blocked` on this path -- `_play`'s own teardown is the repair
411+
# for everything that goes through `Pump.play`, and this except is
412+
# what catches the rest -- so recording a lost race as blocking
413+
# meant the process never reached for the pump again, on any
414+
# player, until it exited (pydevices#52).
415+
transient = isinstance(exc, _pump_mod.StartFailed)
416+
engine.note_fault(str(exc), blocking=not transient)
410417
print("audiodev: the audio pump would not start -", exc,
411-
"- playing on the interpreter thread instead")
418+
"- playing on the interpreter thread instead"
419+
+ ("; the next play will try again" if transient else ""))
412420
return
413421
self._engine = engine
414422
self._engine_seen = True

0 commit comments

Comments
 (0)