Skip to content

fix(media): tear down the play_sound playbin on EOS/error - #1330

Open
xTriZzz wants to merge 2 commits into
pollen-robotics:mainfrom
xTriZzz:840-teardown-play-sound-playbin-on-eos
Open

xTriZzz wants to merge 2 commits into
pollen-robotics:mainfrom
xTriZzz:840-teardown-play-sound-playbin-on-eos

Conversation

@xTriZzz

@xTriZzz xTriZzz commented Aug 7, 2026 •

Copy link
Copy Markdown

Summary

play_sound() creates a playbin, sets it to PLAYING, and never watches its bus. After playback finishes, the last playbin idles in PLAYING with the file loaded indefinitely — until the next play_sound() call, which may never come.

This bug exists in both play_sound implementations, and this PR fixes both:

  • GStreamerAudio.play_sound() (media/audio_gstreamer.py) — first commit
  • GstMediaServer.play_sound() (media/media_server.py) — second commit; this is the implementation the daemon actually uses for wake-up/sleep sounds and POST /api/media/play_sound (at least on Reachy Mini Lite, daemon 1.9.0)

This is the remaining half of #840 (closed for inactivity, but still present on main). #915 fixed the accumulation between plays by storing the playbin and tearing down the previous one, but nothing tears down the last one, so its pipeline threads are never released and the pipeline stays live.

The surprising symptom: spontaneous replay

Beyond the thread leak documented in #840, an idle PLAYING playbin spontaneously replays its loaded file every 12,198 s (3 h 23 m 18 s). Observed on a Reachy Mini Lite, daemon 1.9.0 (Linux host, PipeWire), over a two-day tap of the speaker sink:

  • 11 replay events recorded, intervals of exactly 12,198 s (±1 s); five events predicted in advance to the second.
  • The replayed content tracks the most recently played file: after wake_up.wav plays, the replay is the wake sound; we then played dance1.wav and predicted (in advance) that the next phantom would be the dance jingle instead — it was, to the second, matching dance1.wav at r = 0.999. Each play_sound() tears down the previous playbin (the 892 stop playing has no effect on audio started by play sound gstreamer backend #915 behavior), which also cancels its pending replay — single-slot semantics that match self._playbin exactly.
  • Zero log traces at every event: daemon journal empty, no new PipeWire playback stream (audio emerges from the idle playbin's still-open stream — same node, same object.serial), no API clients, no SSH sessions, no other audio processes.
  • Replays are deterministic: replay-vs-replay comparison gives max sample diff 0.0. Curiously they are not bit-identical to the first (live) pass of the same sound (small diff, ≈4 % of peak worst-case) — the idle pipeline appears to deterministically re-render from its loaded media rather than re-emit captured output. May help whoever hunts the root cause inside GStreamer.
  • Open questions we could not resolve: what inside GStreamer/PipeWire counts exactly 12,198 s (it is not a 2^29-sample counter at 44.1 kHz — that would be 12,173 s), and one anomalous first interval (~4,146 s) observed on the first day.

Audio captures of the sink, waveform correlation analysis, and the event timeline are available on request.

Why both files matter

We initially shipped only the GStreamerAudio fix to the affected robot — and the replays continued unchanged, because the daemon-side path goes through GstMediaServer.play_sound(), which has the identical bug. Only after patching media_server.py did the replays stop. A fix to one twin without the other does not cure a deployed robot.

Fix

Add a bus signal watch to each playbin created by play_sound(). On EOS or ERROR the playbin is set to NULL, the watch removed, and the stored reference cleared (guarded by identity, so a late message from a superseded playbin cannot tear down a newer one). The superseded-playbin path in play_sound(), stop_playing() (GStreamerAudio) and stop_sound() (GstMediaServer) share the same teardown helper, so their bus watches are removed as well.

After the fix (verified on the same robot, both patches applied):

  • play_sound() behavior unchanged audibly; sounds play normally (wake/sleep chimes, API plays).
  • After EOS the playbin reaches NULL (logged) and its PipeWire stream closes; the robot idles with zero open playback streams (pre-fix: the zombie stream persisted indefinitely).
  • The next 12,198 s replay window passed in silence, with the sink tap still armed; no spontaneous replay since (pre-fix: every 12,198 s without exception).
  • Thread count returns to baseline after playback (matches the "after fix" numbers in GStreamer thread leak in play_sound() — playbin never torn down #840).

Tests

tests/unit_tests/test_playbin_teardown.py, in the same fake-self style as test_audio_gstreamer.py, now parametrized over both implementations (GStreamerAudio, GstMediaServer):

  • teardown NULLs the playbin, removes its bus watch, clears _playbin
  • tearing down a superseded playbin leaves the newer _playbin reference intact
  • EOS and ERROR bus messages trigger teardown (ERROR also logs)
  • other bus messages are ignored

ruff check / ruff format clean on the touched files (ruff 0.12.0 as pinned); mypy --strict error delta zero vs main.

xTriZzz and others added 2 commits August 7, 2026 13:19
play_sound() set its playbin to PLAYING and never watched the bus, so
after playback finished the last playbin idled in PLAYING with the file
loaded indefinitely. Its pipeline threads were never released (pollen-robotics#840),
and on hardware the idle pipeline can spontaneously replay the loaded
file — observed on a Reachy Mini Lite (daemon 1.9.0) as a byte-identical
replay of wake_up.wav every 12,198 s with no log trace.

Add a bus signal watch per playbin: on EOS or ERROR the playbin is set
to NULL, its watch removed, and the stored reference cleared. The
superseded-playbin path in play_sound() and stop_playing() now share the
same teardown helper, so their bus watches are dropped as well.

Fixes pollen-robotics#840

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The daemon-side play_sound (GstMediaServer, used for wake-up/sleep and
/api/media/play_sound) has the same missing-EOS-teardown bug as the
GStreamerAudio twin fixed in the previous commit — and on Reachy Mini
Lite it is the implementation that actually runs. A playbin left in
PLAYING after EOS was observed replaying its loaded file every ~12198s
with no log trace (11 recorded occurrences over two days; replay content
tracks the most recently played file). Applying the same bus-watch
teardown here resolved it: the periodic replay window passed silent
after the fix.

Routes stop_sound and the stale-playbin swap in play_sound through the
shared _teardown_playbin helper, and parametrizes the teardown unit
tests over both implementations.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@xTriZzz

xTriZzz commented Aug 13, 2026

Copy link
Copy Markdown
Author

Flagging an overlap: #1332 prerolls play_sound playbins to PAUSED and keeps them warm, and this PR tears them down on EOS/error. Both touch media/media_server.py, so they'll likely conflict — happy to rebase onto #1332 once it lands, or to close this if prerolling makes the teardown moot. I don't think it does, but @tfrere is better placed to judge that than I am.

Context that might help either way, since the failure mode is easy to miss: a leaked playbin doesn't just leak a thread. It stays in PLAYING with the last file still loaded, and something in the stack re-triggers it on a fixed interval — a robot with no process running and nothing in the daemon journal will replay the last sound it was asked to make, byte-identical, every 12,198 seconds.

I caught eleven of these over three nights with a capture tap on the sink (nothing appears in the journal or the stream graph — only the wire hears it), then predicted five in advance to the second before patching. Correlation between replays is 1.000000; max sample difference is zero.

Worth noting play_sound exists twice — media/audio_gstreamer.py and media/media_server.py. Patching only the first looks like a failed fix, because the daemon runs the second. This PR does both.

Related: #840 described the same leak and was closed for inactivity.

Tests are in tests/unit_tests/test_playbin_teardown.py. CI hasn't run on this branch — I think it needs a maintainer to approve the workflow.

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant