Sound Issues Using SoX

[RandyR]

I built a new image today using the latest RPiOS Trixie Desktop and added support for x86_64 engines. While testing I switched to SoX as the audio backend (pipewire-alsa is installed) and tested the added engines. I had engine issues with the Linux StockfishDD which were likely due to the engine analysis. The log showed the following:

2026-04-24 10:34:38.647 WARNING     engine - stop_async: engine analyser stop timed out after 1.0s - cancelling task
2026-04-24 10:34:47.632   ERROR base_events - default_exception_handler: Exception in callback Protocol.pipe_data_received()
handle: <Handle Protocol.pipe_data_received()>
Traceback (most recent call last):
  File "/usr/lib/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
    ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/picochess/venv/lib/python3.13/site-packages/chess/engine.py", line 968, in pipe_data_received
    self._line_received(line)
    ~~~~~~~~~~~~~~~~~~~^^^^^^
  File "/opt/picochess/venv/lib/python3.13/site-packages/chess/engine.py", line 981, in _line_received
    self.command._line_received(line)
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
  File "/opt/picochess/venv/lib/python3.13/site-packages/chess/engine.py", line 1294, in _line_received
    self.line_received(line)
    ~~~~~~~~~~~~~~~~~~^^^^^^
  File "/opt/picochess/venv/lib/python3.13/site-packages/chess/engine.py", line 1445, in line_received
    self.result.set_result(None)
    ~~~~~~~~~~~~~~~~~~~~~~^^^^^^
asyncio.exceptions.InvalidStateError: invalid state
2026-04-24 10:34:59.820 WARNING     engine - _analyse_forever: engine engine not ready, analysis may fail
2026-04-24 10:35:15.648 WARNING     engine - stop_async: engine analyser stop timed out after 1.0s - cancelling task
2026-04-24 10:35:15.649   ERROR     engine - _engine_task: engine (playing) unexpected error during play_move: CommandState.NEW
Traceback (most recent call last):
  File "/opt/picochess/uci/engine.py", line 797, in _engine_task
    analysis = await self.engine.analysis(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ...<5 lines>...
    )
    ^
  File "/opt/picochess/venv/lib/python3.13/site-packages/chess/engine.py", line 1774, in analysis
    return await self.communicate(UciAnalysisCommand)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/picochess/venv/lib/python3.13/site-packages/chess/engine.py", line 997, in communicate
    self.next_command.set_finished()
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^
  File "/opt/picochess/venv/lib/python3.13/site-packages/chess/engine.py", line 1269, in set_finished
    assert self.state in [CommandState.ACTIVE, CommandState.CANCELLING], self.state
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError: CommandState.NEW
2026-04-24 10:35:15.652   ERROR  picochess - think: Engine returned Exception when asked to make a move
2026-04-24 10:35:15.653 WARNING     engine - handle_bestmove_0000: engine ping failed with unexpected state: CommandState.NEW
2026-04-24 10:35:16.401   ERROR  picochess - process_main_events: engine crashed - game has not ended
2026-04-24 10:35:16.670 WARNING     engine - _analyse_forever: engine engine not ready, analysis may fail
2026-04-24 10:35:16.670 WARNING     engine - _handle_protocol_state_failure: engine continuous analysis protocol failure: AssertionError: CommandState.NEW
2026-04-24 10:35:16.670 WARNING     engine - _recover_from_failed_analyser_stop: continuous analysis protocol failure: AssertionError: CommandState.NEW - restarting engine Stockfish DD 64 SSE4.2
2026-04-24 10:35:16.741   ERROR base_events - default_exception_handler: UciAnalysisCommand failed after returning preliminary result (<Future cancelled>)
protocol: <UciProtocol (pid=1861)>
transport: <_UnixSubprocessTransport pid=1861 returncode=0 stdin=<_UnixWritePipeTransport closed fd=14 closed> stdout=<_UnixReadPipeTransport closed fd=15 closed> stderr=<_UnixReadPipeTransport closed fd=24 closed>>
chess.engine.EngineTerminatedError: engine process died unexpectedly (exit code: 0)
2026-04-24 10:35:17.605 WARNING  picotutor - pop_last_move: picotutor eval for next move must be done without history
2026-04-24 10:35:17.678 WARNING     engine - start_analysis: start analysis requested but no engine loaded
2026-04-24 10:35:18.680 WARNING     engine - start_analysis: start analysis requested but no engine loaded

I  added 'Analysis = false' to stockfishdd.uci and that seemed to sort it out.

But, I've noticed that when restarting a game (I'm using no-eboard mode) I lose the sound (No "Engine Setup" or "OK") and no more move announcements. I see the same issue when using the Windows stockfish16.exe engine. I can play sound by logging in via ssh ('play /opt/picochess/talker/voices/en/christina/verygoodmove.ogg') and no errors show in the log. I'll do more testing to see if I can learn anything. I'm on master (commit 57e8f87e).

Randy

[RandyR]

I switched to Native and restarted PicoChess, and the sound seemed fine but I didn't do too many tests. Switched back to Sox and a different engine (Cray Blitz) and noticed when playing Fool's Mate, when the engine made its last move and announced "Queen H 4" I didn't hear "Checkmate Black Wins". I looked at systemctl status picochess and it looks like the play command is hanging and blocking anything further:

pi@picochess:~ $ systemctl status picochess
● picochess.service - PicoChess Chess Program
     Loaded: loaded (/etc/systemd/system/picochess.service; enabled; preset: enabled)
     Active: active (running) since Fri 2026-04-24 13:20:36 CDT; 3min 59s ago
 Invocation: cc60e4fd13b5475e84da0ff3e062b366
   Main PID: 2272 (python3)
      Tasks: 57 (limit: 8746)
        CPU: 41.831s
     CGroup: /system.slice/picochess.service
             ├─2272 /opt/picochess/venv/bin/python3 /opt/picochess/picochess.py
             ├─2329 /bin/bash /opt/picochess/engines/aarch64/windows64/crayblitz
             ├─2330 start.exe 11.4/lib/wine/x86_64-unix/wine ./CrayBlitzUCI.exe
             ├─2335 /opt/wine-11.4/lib/wine/../../bin/wineserver
             ├─2341 services.exe 4/lib/wine/x86_64-unix/wine "C:\\windows\\system32\\services.exe"
             ├─2345 winedevice.exe lib/wine/x86_64-unix/wine "C:\\windows\\system32\\winedevice.exe"
             ├─2354 plugplay.exe 4/lib/wine/x86_64-unix/wine "C:\\windows\\system32\\plugplay.exe"
             ├─2360 svchost.exe .4/lib/wine/x86_64-unix/wine "C:\\windows\\system32\\svchost.exe" -k LocalServiceNetworkRestricted
             ├─2366 winedevice.exe lib/wine/x86_64-unix/wine "C:\\windows\\system32\\winedevice.exe"
             ├─2384 CrayBlitzUCI.exe b/wine/x86_64-unix/wine "F:\\opt\\picochess\\engines\\aarch64\\windows64\\Cray_Blitz\\CrayBlitzUCI.exe"
             ├─2395 /opt/picochess/engines/aarch64/a-stockf
             ├─2399 /opt/picochess/engines/aarch64/a-stockf
             ├─2544 inbetween.exe /lib/wine/x86_64-unix/wine inbetween.exe
             ├─2547 cray-blitz.exe lib/wine/x86_64-unix/wine cray-blitz.exe
             └─2646 play talker/voices/en/christina/checkmate.ogg tempo 1.15

I am able to play the checkmate.ogg file via ssh. Using htop I can see it is stuck:

If I enter the "sudo systemctl restart picochess" command, I then hear "Black Wins" before it restarts.

Also, it's not just x86_64 engines. I just tested with StockfishNN with the moves f3 d5 g4 c5 and when SF played c5 all I heard was "C" and not the "5". htop shows:

Randy

[RandyR]

Not sure if it's related - I switched to Native and played against StockfishNN. It took a while to lose but after 1. f3 d5 2. g4 c5 3. Nc3 g6 4. a4 Nc6 5. f4 Bxg4 6. h3 Bh5 7. Nb5 a6 8. Nc3 e6 9. Nxd5 Qh4, I heard "Queen H 4 ...... Black Wins". The "Checkmate" was silent/muted. Could this be a buffer issue? And in the case with SoX, sox doesn't receive anything back saying the sound has finished playing? Just a non-programmer speculating...

Randy

[Johan Sjöblom]

Nice testing. I hotfixed master with fixes on the sox sound.

[RandyR]

Thanks, Johan. Unfortunately that doesn't really fix the issue. It just prevents a permanent lockup of the sound. I played against SF18 and got 2 non-playing .ogg files in just a few moves:

2026-04-25 09:42:39.792 WARNING picotalker - pico3_sound_player: SoX play timed out after 12.0s for talker/voices/en/christina/d.ogg
2026-04-25 09:43:11.028 WARNING picotalker - pico3_sound_player: SoX play timed out after 12.0s for talker/voices/en/christina/h.ogg

Any idea what could be causing this? Any way I can test SoX to rule it out to determine if it's a PicoChess issue? SoX was previously very reliable but I'm not ruling out OS changes (Pipewire) causing the issue.

Randy

[Randy Reade]

I can have SoX playing sounds constantly while PicoChess is playing and announcing sounds and there is no lockup noticed and both streams will play so it does seem internal to PicoChess. I just used something like this in a terminal while playing a game:

' play a.ogg 7.ogg a.ogg 5.ogg checkmate.ogg && play verygoodmove.ogg && play a.ogg 7.ogg a.ogg 5.ogg checkmate.ogg && play verygoodmove.ogg &&play a.ogg 7.ogg a.ogg 5.ogg checkmate.ogg && play verygoodmove.ogg &&play a.ogg 7.ogg a.ogg 5.ogg checkmate.ogg && play verygoodmove.ogg'

Randy

--
You received this message because you are subscribed to the Google Groups "PicoChess" group.
To unsubscribe from this group and stop receiving emails from it, send an email to picochess+...@googlegroups.com.
To view this discussion visit https://groups.google.com/d/msgid/picochess/c75a9fb0-2882-465a-a53b-9e1917f53fb5n%40googlegroups.com.

[RandyR]

Also, with SoX looping at the same time there doesn't seem to be any lockups in PicoChess. Maybe that's a clue. I played a full 42 move game at 5 sec/move and there were no warnings in the log.

Randy

[Johan Sjöblom]

Tricky...

best guess: its SoX plus the current audio stack getting stuck when PicoChess repeatedly opens/closes the output device for very short clips. Its probably exposed by PicoChess’ per-clip SoX design, but the actual hang is inside play/ALSA/PipeWire.

best way to avoid it? use audio-backend = native

Your Sox test oneliner runs all Sox sounds in one process... Pico runs one process at a time.... Thats probably the problem.

have to create some test-scripts in bash or python for you to run to be sure...

[Randy Reade]

It's actually multiple consecutive play commands that I'm using but I don't know enough about how SoX handles this to know if it matches what PicoChess does. SoX itself has no issues playing multiple small clips consecutively, over and over again.

I could try using an old version of the OS, maybe Bookworm to see if the issue is there. 

Randy

To view this discussion visit https://groups.google.com/d/msgid/picochess/02eb57e4-8cd3-4af1-8b1c-4eff232c0ffcn%40googlegroups.com.

[Johan Sjöblom]

I dont think we need to support Sox in the newest Raspbian OS. The SOX support is there only to have backward compatibility for Bookworm or older. Could this be a viable strategy?

[Randy Reade]

Certainly. I guess the only reason I like to use it is for the volume normalization. And it doesn't seem to have the sound fade-in/out issues that Native has, but the current SoX issue is worse than that annoyance.

I don't recall why the change was made from SoX on the Desktop OS installs. Maybe you can remind me.

Randy

To view this discussion visit https://groups.google.com/d/msgid/picochess/5bb3641e-67de-4aa5-aaa8-3795f726a049n%40googlegroups.com.

[Johan Sjöblom]

Oh, my memory fails me, but without checking my notes from back then I would say that the main reason for abandoning Sox was to be independent of pulseaudio and allow any sound setting like alsa, pipewire...

The other reason is that the native sound is produced as a stream that never closes and can be used without a blocking system call.

So in theory I should be able to fix any sound issue with native :-) Including but not limited to, as legal texts say, the normalisation of sound. If I remember correctly I did analyse the ogg sound files and they are not normalised. Sox probably fixes that...

I wonder, is the high cpu usage back to haunt us in the startup... there was so many changes since last version so I might have broken the "do not spend cpu" design on startup.

If you can state what native sound problems are I can have another go at it. Normalisation, and still loosing some part of the end?

To view this discussion visit https://groups.google.com/d/msgid/picochess/CAE5WduuH%2B7OdTGeyLt%3DxPd20c8-svwfpUh09m%2BbD7%2B3Amsv0Rg%40mail.gmail.com.

[Randy Reade]

Yeah, the sound files are normalized via metadata which SoX reads and uses to adjust the volume. The actual .ogg data is unchanged. We could normalize the actual data but that's destructive.

I haven't been using Native in a while so will switch and see how testing goes. Maybe someone else can provide some feedback so I know it's not just me. 😊

There does seem to be some startup overhead but it's hard to say if it's PicoChess or the OS. I've seen some sluggishness after initial boot where PicoChess seems frozen for a bit so I've just learned to wait a while before starting the testing. I usually wait a bit anyway so the fake RTC gets updated as I've seen time anomalies when it happens during a game and by checking the current time and looking at journalctl I noticed the anomaly happened when the time change was applied.

Randy

To view this discussion visit https://groups.google.com/d/msgid/picochess/CAEk%2BOSReyprRAv%3DsL0pWLP22OoSHJkrkNJgOAFqSWnLSytGL-Q%40mail.gmail.com.

[RandyR]

I was doing some research into PipeWire sound issues (muting/delay/cutting off the first part of audio - needing a bit of time to start up) and one of the workarounds was to use SoX to keep the "pipe" open so to speak. SoX has a null option (-n) that can be used for this purpose. All that is needed is to run the command 'play -V1qn' (-V1: verbosity level 1 - only show failures; -q: quiet mode - don't show progress; -n: use the null file handler) and the short audio files are all heard. I'll have to test more but it also seems to fix the issue that led to this thread.

It would be simple to add this to the service unit that starts PicoChess or in the python code.

Randy

[Randy Reade]

Probably a better command would be 'play -V1qn > /dev/null 2>&1 &'.

Randy

[RandyR]

Correction. That command will fail. It should be 'play -nqV1 > /dev/null 2>&1 &'.