snapcast icon indicating copy to clipboard operation
snapcast copied to clipboard

Defunct child processes created when using script mixer in snapclient

Open brianskrab opened this issue 9 months ago • 1 comments

Describe the bug Running snapclient in script mixer mode creates a defunct process for each invocation of the mixer script upon adjusting the snapclient volume via a command from the snapserver.

This appears to be caused by the snapclient immediately detaching from the child process and never waiting for it to complete. My understanding is that until the child is collected it will remain in the process table. In this case, the detached child processes are only removed from the process table when the parent process exits.

Forking the process twice appears to be a common way to solve this on UNIX systems. The main process forks a child process and waits for it. The child process forks and execs the script, immediately detaches from the grandchild process that is running the script and exits. This keeps the wait in the main process short and allows the detached grandchild process to be collected by the system because its parent process has completed.

From what I can tell, the Boost process library does not support this kind of process management due to its lack of portability between systems. Any way to make snapclient wait on the volume script process?

Steps to Reproduce

  1. Install snapclient from package: sudo apt install snapclient
  2. Configure snapclient to run a script to set volume: Set SNAPCLIENT_OPTS="--mixer script:/home/pi/bin/snapclient-volume.sh" in /etc/default/snapclient and restart the snapclient sudo service restart snapclient
  3. Adjust the volume for the client on the snapserver
  4. Observe a defunct process for each time the volume was adjusted

Environment details

  • OS: Raspbian GNU/Linux 11 (bullseye)
  • Snapcast version: snapclient v0.23.0
  • Installed from: apt install snapclient

Attach logfile if applicable Generate logs with snapclient --logfilter debug or snapserver --logging.filter debug if possible and paste them in the following codeblock

Sep 17 18:09:05 raspberrypi snapclient[21675]: Snapclient terminated.
Sep 17 18:09:05 raspberrypi snapclient[5729]: (Browser) CACHE_EXHAUSTED
Sep 17 18:09:05 raspberrypi snapclient[5729]: (Browser) NEW: service 'Snapcast' of type '_snapcast._tcp' in domain 'local'
Sep 17 18:09:05 raspberrypi snapclient[5729]: Service 'Snapcast' of type '_snapcast._tcp' in domain 'local':
Sep 17 18:09:05 raspberrypi snapclient[5729]: #011snapserver.local:1704 (10.0.1.34)
Sep 17 18:09:05 raspberrypi snapclient[5729]: Found server 10.0.1.34:1704
Sep 17 18:09:05 raspberrypi snapclient[5729]: Resolving host IP for: 10.0.1.34
Sep 17 18:09:05 raspberrypi snapclient[5729]: Connecting
Sep 17 18:09:05 raspberrypi snapclient[5729]: Connected to 10.0.1.34
Sep 17 18:09:05 raspberrypi snapclient[5729]: My MAC: "00:e0:4c:36:05:c9", socket: 8
Sep 17 18:09:07 raspberrypi snapclient[5729]: ServerSettings - buffer: 500, latency: 0, volume: 57, muted: 0
Sep 17 18:09:07 raspberrypi snapclient[5729]: Codec: flac, sampleformat: 48000:16:2
Sep 17 18:09:07 raspberrypi snapclient[5729]: Player name: alsa, device: default, description: <none>, idx: 4, sharing mode: unspecified, parameters: <none>
Sep 17 18:09:07 raspberrypi snapclient[5729]: Mixer mode: script, parameters: /home/pi/bin/snapclient-volume.sh
Sep 17 18:09:07 raspberrypi snapclient[5729]: Sampleformat: 48000:16:2, stream: 48000:16:2
Sep 17 18:09:07 raspberrypi snapclient[5729]: Using buffer_time: 80 ms, fragments: 4
Sep 17 18:09:07 raspberrypi snapclient[5729]: PCM name: default, sample rate: 48000 Hz, channels: 2, buffer time: 69645 us, periods: 3, period time: 23219 us, period frames: 1114
Sep 17 18:09:07 raspberrypi snapclient[5729]: No chunks available
Sep 17 18:09:07 raspberrypi snapclient[5729]: Failed to get chunk
Sep 17 18:09:07 raspberrypi snapclient[5729]: diff to server [ms]: 3.09088e+09
Sep 17 18:09:12 raspberrypi snapclient[5729]: No chunk received for 5000ms. Closing ALSA.
Sep 17 18:09:25 raspberrypi snapclient[5729]: Resolving host IP for: 10.0.1.34
Sep 17 18:09:25 raspberrypi snapclient[5729]: Connecting
Sep 17 18:09:26 raspberrypi snapclient[5729]: Resolving host IP for: 10.0.1.34
Sep 17 18:09:26 raspberrypi snapclient[5729]: Connecting
Sep 17 18:09:27 raspberrypi snapclient[5729]: Resolving host IP for: 10.0.1.34
Sep 17 18:09:27 raspberrypi snapclient[5729]: Connecting
Sep 17 18:09:28 raspberrypi snapclient[5729]: Resolving host IP for: 10.0.1.34
Sep 17 18:09:28 raspberrypi snapclient[5729]: Connecting
Sep 17 18:09:29 raspberrypi snapclient[5729]: Resolving host IP for: 10.0.1.34
Sep 17 18:09:29 raspberrypi snapclient[5729]: Connecting
Sep 17 18:09:30 raspberrypi snapclient[5729]: Resolving host IP for: 10.0.1.34
Sep 17 18:09:30 raspberrypi snapclient[5729]: Connecting
Sep 17 18:09:31 raspberrypi snapclient[5729]: Resolving host IP for: 10.0.1.34
Sep 17 18:09:31 raspberrypi snapclient[5729]: Connecting
Sep 17 18:09:31 raspberrypi snapclient[5729]: Connected to 10.0.1.34
Sep 17 18:09:31 raspberrypi snapclient[5729]: My MAC: "00:e0:4c:36:05:c9", socket: 8
Sep 17 18:09:31 raspberrypi snapclient[5729]: ServerSettings - buffer: 500, latency: 0, volume: 57, muted: 0
Sep 17 18:09:31 raspberrypi snapclient[5729]: Codec: flac, sampleformat: 48000:16:2
Sep 17 18:09:31 raspberrypi snapclient[5729]: Player name: alsa, device: default, description: <none>, idx: 4, sharing mode: unspecified, parameters: <none>
Sep 17 18:09:31 raspberrypi snapclient[5729]: Mixer mode: script, parameters: /home/pi/bin/snapclient-volume.sh
Sep 17 18:09:31 raspberrypi snapclient[5729]: Sampleformat: 48000:16:2, stream: 48000:16:2
Sep 17 18:09:31 raspberrypi snapclient[5729]: Using buffer_time: 80 ms, fragments: 4
Sep 17 18:09:31 raspberrypi snapclient[5729]: PCM name: default, sample rate: 48000 Hz, channels: 2, buffer time: 69645 us, periods: 3, period time: 23219 us, period frames: 1114
Sep 17 18:09:31 raspberrypi snapclient[5729]: No chunks available
Sep 17 18:09:31 raspberrypi snapclient[5729]: Failed to get chunk
Sep 17 18:09:31 raspberrypi snapclient[5729]: diff to server [ms]: 3.09088e+09
Sep 17 18:09:36 raspberrypi snapclient[5729]: No chunk received for 5000ms. Closing ALSA.
Sep 17 18:15:34 raspberrypi snapclient[5729]: ServerSettings - buffer: 500, latency: 0, volume: 58, muted: 0
Sep 17 18:15:45 raspberrypi snapclient[5729]: ServerSettings - buffer: 500, latency: 0, volume: 59, muted: 0
Sep 17 18:15:54 raspberrypi snapclient[5729]: ServerSettings - buffer: 500, latency: 0, volume: 60, muted: 0

Finding Defunct Processes

# List of defunct processes for the mixer script
# One process per ServerSettings line in log file
$ ps -ef | grep defunct
_snapcl+  5735  5729  0 18:09 ?        00:00:00 [snapclient-volu] <defunct>
_snapcl+  5900  5729  0 18:09 ?        00:00:00 [snapclient-volu] <defunct>
_snapcl+  6529  5729  0 18:15 ?        00:00:00 [snapclient-volu] <defunct>
_snapcl+  6534  5729  0 18:15 ?        00:00:00 [snapclient-volu] <defunct>
_snapcl+  6544  5729  0 18:15 ?        00:00:00 [snapclient-volu] <defunct>
pi        6830  1416  0 18:18 pts/2    00:00:00 grep --color=auto defunct

# Parent process
$ ps -p 5729
  PID TTY          TIME CMD
 5729 ?        00:00:05 snapclient

# Child processes are cleaned up upon stopping snapclient
$ sudo service snapclient stop
$ ps -ef | grep defunct
pi        7845  1416  0 18:27 pts/2    00:00:00 grep --color=auto defunct

brianskrab avatar Sep 17 '23 22:09 brianskrab

I can confirm this behavior for snapclient v0.27.0 compiled for OpenWRT on raspberrypi.

16194 root      7600 S    /usr/bin/snapclient --host 192.168.120.71 --port 1704 --hostID two-right --soundcard right --player alsa --sampleformat 48000:16:* --mixer script:/usr/local/bin/volume-right.sh --logfilter *:warning
16196 root      7556 S    /usr/bin/snapclient --host 192.168.120.71 --port 1704 --hostID two-left --soundcard left --player alsa --sampleformat 48000:16:* --mixer script:/usr/local/bin/volume-left.sh --logfilter *:warning
16232 root         0 Z    [volume-right.sh]
16233 root         0 Z    [volume-left.sh]
16292 root         0 Z    [volume-right.sh]
16332 root         0 Z    [volume-right.sh]
16339 root         0 Z    [volume-right.sh]
16371 root         0 Z    [volume-right.sh]
25731 root         0 Z    [volume-right.sh]
25736 root         0 Z    [volume-right.sh]
25835 root         0 Z    [volume-right.sh]
25934 root         0 Z    [volume-right.sh]

toffee avatar Nov 24 '23 21:11 toffee

This is fixed now in the develop branch. You can find debian packages here: https://github.com/badaix/snapcast/actions/runs/8506305673

badaix avatar Mar 31 '24 20:03 badaix

Fixed in version 0.28.0

badaix avatar Apr 19 '24 16:04 badaix