Describe the bug
Snapclient cannot playback via ALSA PCM when the output device (-s) is a dshare. Snapclient will report repeated messages suggesting the PCM device is in an invalid state. Bug can be traced to the change to alsa_player.cpp at commit 273ad9622847ee8fa73d5de9de6bea99b34d352f. Bug persists through the current commit. Commenting out the offending code block from the current commit restores playback functionality.
Steps to Reproduce
Set up a dshare in /etc/asound.conf to split a USB sound card into multiple outputs
Run snapclient and target a dshare output device.
Observe no playback and error messages in the logfile.
Environment details
OS: Raspbian Bullseye on Pi3B+ with external USB 7.1 sound card
Snapcast version 0.23.0 and up since 273ad9622847ee8fa73d5de9de6bea99b34d352f.
Installed from a package, self compiled, ... - Either.
Attach logfile if applicable
Generate logs with snapclient --logfilter debug or snapserver --logging.filter debug if possible and paste them in the following codeblock
Clean startup with working v0.22.0 Release (installed from package)
Bad startup with failing v0.23.0 Release (installed from package)
$ snapclient -s src2 -h 192.168.1.10 -p 1234 -i 3 --logfilter *:trace --debug
2023-08-31 14-13-55.099 [Info] (Connection) Resolving host IP for: 192.168.1.10
2023-08-31 14-13-55.100 [Info] (Connection) Connecting
2023-08-31 14-13-55.115 [Notice] (Connection) Connected to 192.168.1.10
2023-08-31 14-13-55.116 [Info] (Connection) My MAC: "b8:[redacted]", socket: 8
2023-08-31 14-13-55.342 [Debug] (Connection) outstanding async_write
2023-08-31 14-13-55.342 [Trace] (Connection) Wrote 247 bytes to socket
2023-08-31 14-13-55.343 [Trace] (Connection) Wrote 34 bytes to socket
2023-08-31 14-13-55.348 [Info] (Controller) ServerSettings - buffer: 1000, latency: 0, volume: 100, muted: 0
2023-08-31 14-13-55.353 [Info] (Controller) Codec: flac, sampleformat: 48000:16:2
2023-08-31 14-13-55.353 [Info] (Player) Player name: alsa, device: src2_dshare, description: <none>, idx: 3, sharing mode: unspecified, parameters: <none>
2023-08-31 14-13-55.353 [Info] (Player) Mixer mode: software, parameters: <none>
2023-08-31 14-13-55.353 [Info] (Player) Sampleformat: 48000:16:2, stream: 48000:16:2
2023-08-31 14-13-55.353 [Info] (Alsa) Using buffer_time: 80 ms, fragments: 4
2023-08-31 14-13-55.361 [Info] (Alsa) PCM name: src2_dshare, sample rate: 48000 Hz, channels: 2, buffer time: 85333 us, periods: 4, period time: 21333 us, period frames: 1024
2023-08-31 14-13-55.362 [Debug] (Player) setVolume exp with base 10: 1 => 1
2023-08-31 14-13-55.362 [Debug] (Player) snd_pcm_avail_delay failed: File descriptor in bad state (-77), avail: 0, delay: -1472036457, using snd_pcm_avail amd snd_pcm_delay.
2023-08-31 14-13-55.363 [Trace] (Connection) Wrote 34 bytes to socket
2023-08-31 14-13-55.363 [Debug] (Alsa) snd_pcm_avail failed: File descriptor in bad state (-77), using 1024
2023-08-31 14-13-55.363 [Debug] (Alsa) Resizing buffer from 0 to 4096
2023-08-31 14-13-55.364 [Info] (Stream) No chunks available
2023-08-31 14-13-55.364 [Info] (Alsa) Failed to get chunk
In both cases above, the snapserver is not sending chunks yet. When chunks are sent, the failing client will repeatedly log:
2023-08-31 14-13-58.806 [Warn] (Alsa) snd_pcm_avail_delay failed: File descriptor in bad state (-77), avail: 1024, delay: 0, using snd_pcm_avail amd snd_pcm_delay.
2023-08-31 14-13-58.809 [Debug] (Alsa) snd_pcm_avail failed: File descriptor in bad state (-77), using 1024
2023-08-31 14-13-58.809 [Error] (Alsa) ERROR. Can't write to PCM device: File descriptor in bad state
2023-08-31 14-13-58.817 [Info] (Alsa) PCM name: src2_dshare, sample rate: 48000 Hz, channels: 2, buffer time: 85333 us, periods: 4, period time: 21333 us, period frames: 1024
as the chunks come in.
Contents of asound.conf:
# shared buffer for playback
pcm_slave.tdmshare {
# pcm "surround71:ICUSBAUDIO7D,0" # define the sound card
pcm "hw:ICUSBAUDIO7D,0"
channels 8
rate 48000 # fixed, because all dshare devices must use the same >
format S16_LE
# period_time 0
period_size 1024
buffer_size 4096
}
# src1 shared pcm device and corresponding virtual playback device
pcm.src1_dshare {
type dshare
ipc_key 43544553
slave tdmshare
bindings.0 0
bindings.1 1
}
pcm.src1 {
type plug
slave.pcm "src1_dshare"
hint {
show {
@func refer
name defaults.namehint.basic
}
description "USB sound card FRONT output jack"
}
}
# src2 shared pcm device and corresponding virtual playback device
pcm.src2_dshare {
type dshare
ipc_key 43544553
slave tdmshare
bindings.0 6
bindings.1 7
}
pcm.src2 {
type plug
slave.pcm "src2_dshare"
hint {
show {
@func refer
name defaults.namehint.basic
}
description "USB sound card SURROUND output jack"
}
}
# src3 shared pcm device and corresponding virtual playback device
pcm.src3_dshare {
type dshare
ipc_key 43544553
slave tdmshare
bindings.0 2
bindings.1 3
}
pcm.src3 {
type plug
slave.pcm "src3_dshare"
hint {
show {
@func refer
name defaults.namehint.basic
}
description "USB sound card CENTER/BASS output jack"
}
}
# src4 shared pcm device and corresponding virtual playback device
pcm.src4_dshare {
type dshare
ipc_key 43544553
slave tdmshare
bindings.0 4
bindings.1 5
}
pcm.src4 {
type plug
slave.pcm "src4_dshare"
hint {
show {
@func refer
name defaults.namehint.basic
}
description "USB sound card BACK output jack"
}
}
Issue does not occur when using non-dshare outputs such as the native headphone output from the Pi.
Perhaps it's an issue with how I've set up the dshare. I've yet to digest how those few lines of code in alsa_player are breaking the PCM output.
I did instrument one build to monitor the state, and snapclient reported it to be PREPARED the whole time it was choking on chunks.
Again, deleting lines 448-452 from the v0.27.0 release of alsa_player.cpp gives me a working build at the latest rev.
Describe the bug Snapclient cannot playback via ALSA PCM when the output device (-s) is a dshare. Snapclient will report repeated messages suggesting the PCM device is in an invalid state. Bug can be traced to the change to alsa_player.cpp at commit 273ad9622847ee8fa73d5de9de6bea99b34d352f. Bug persists through the current commit. Commenting out the offending code block from the current commit restores playback functionality.
Steps to Reproduce
Environment details
Attach logfile if applicable Generate logs with
snapclient --logfilter debug
orsnapserver --logging.filter debug
if possible and paste them in the following codeblockClean startup with working v0.22.0 Release (installed from package)
Bad startup with failing v0.23.0 Release (installed from package)
In both cases above, the snapserver is not sending chunks yet. When chunks are sent, the failing client will repeatedly log:
as the chunks come in.
Contents of asound.conf:
Issue does not occur when using non-dshare outputs such as the native headphone output from the Pi. Perhaps it's an issue with how I've set up the dshare. I've yet to digest how those few lines of code in alsa_player are breaking the PCM output. I did instrument one build to monitor the state, and snapclient reported it to be PREPARED the whole time it was choking on chunks. Again, deleting lines 448-452 from the v0.27.0 release of alsa_player.cpp gives me a working build at the latest rev.