music dropouts/block completely on snapserver

[amigthea]

I'm trying to get snapserver to source from my alsa device but I get this kind of logs, what it could be? a resample problem?

snapcast source configuration

source = alsa://?device=default&name=default
sampleformat = 44100:16:2
codec = pcm

if I record to a file and then play it on my pc it has no problem
arecord -D default -f S16_LE -r 44100 capture.wav

logs

snapcast  | 2024-05-11 08-43-49.448 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.448 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.464 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.464 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.481 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.481 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.497 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.497 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.513 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.513 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.529 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.529 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.545 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.545 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.561 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.561 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.577 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.577 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.593 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.593 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.609 [Info] (AlsaStream) Not enough data available: 14 ms, missing: 6 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.609 [Info] (Server) onResync (default): 16 ms
snapcast  | 2024-05-11 08-43-49.646 [Info] (AlsaStream) Not enough data available: 17 ms, missing: 3 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.646 [Info] (Server) onResync (default): 13 ms
snapcast  | 2024-05-11 08-43-49.659 [Info] (AlsaStream) Too many frames available, fast forwarding from 2839 frames (64.3764 ms) to 1323 frames (30 ms)
snapcast  | 2024-05-11 08-43-49.679 [Info] (AlsaStream) Not enough data available: 10 ms, missing: 10 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.679 [Info] (Server) onResync (default): 20 ms
snapcast  | 2024-05-11 08-43-49.739 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.739 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-49.753 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.753 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-49.807 [Info] (PcmStream) State changed: default, state: playing => idle
snapcast  | 2024-05-11 08-43-49.807 [Info] (Server) onStateChanged (default): idle
snapcast  | 2024-05-11 08-43-49.827 [Info] (PcmStream) State changed: default, state: idle => playing
snapcast  | 2024-05-11 08-43-49.827 [Info] (Server) onStateChanged (default): playing
snapcast  | 2024-05-11 08-43-49.927 [Info] (AlsaStream) Not enough data available: 18 ms, missing: 2 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.927 [Info] (Server) onResync (default): 12 ms
snapcast  | 2024-05-11 08-43-49.939 [Info] (AlsaStream) Too many frames available, fast forwarding from 2885 frames (65.4195 ms) to 1323 frames (30 ms)
snapcast  | 2024-05-11 08-43-49.959 [Info] (AlsaStream) Not enough data available: 10 ms, missing: 10 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-49.959 [Info] (Server) onResync (default): 20 ms
snapcast  | 2024-05-11 08-43-50.000 [Info] (AlsaStream) Not enough data available: 13 ms, missing: 7 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-50.000 [Info] (Server) onResync (default): 17 ms
snapcast  | 2024-05-11 08-43-50.037 [Info] (AlsaStream) Too many frames available, fast forwarding from 2773 frames (62.8798 ms) to 1323 frames (30 ms)
snapcast  | 2024-05-11 08-43-50.837 [Info] (AlsaStream) Not enough data available: 19 ms, missing: 1 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-50.837 [Info] (Server) onResync (default): 11 ms
snapcast  | 2024-05-11 08-43-50.848 [Info] (AlsaStream) Not enough data available: 19 ms, missing: 1 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-50.848 [Info] (Server) onResync (default): 11 ms
snapcast  | 2024-05-11 08-43-50.879 [Info] (AlsaStream) Too many frames available, fast forwarding from 3049 frames (69.1383 ms) to 1323 frames (30 ms)
snapcast  | 2024-05-11 08-43-50.919 [Info] (AlsaStream) Not enough data available: 13 ms, missing: 7 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-50.919 [Info] (Server) onResync (default): 17 ms
snapcast  | 2024-05-11 08-43-50.956 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-50.956 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-50.970 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-50.970 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-50.984 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-50.984 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-50.999 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-50.999 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-51.013 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-51.013 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-51.027 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-51.027 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-51.041 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-51.041 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-51.055 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-51.055 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-51.069 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-51.069 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-51.083 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-51.083 [Info] (Server) onResync (default): 14 ms
snapcast  | 2024-05-11 08-43-51.097 [Info] (AlsaStream) Not enough data available: 16 ms, missing: 4 ms, needed: 20 ms
snapcast  | 2024-05-11 08-43-51.097 [Info] (Server) onResync (default): 14 ms

I tried to change those values from the default but to no avail:

chunk_ms = 20
buffer = 1000

I can ear the audio problem both on software snapclients and snapweb clients.

I'm sure I'm missing something out, would be really glad if someone helps me out
Thank you and keep up with this amazing project!

[amigthea]

I confirmed that every time that a dropout appear it's because the PcmStream goes from idle to playing and back

snapcast  | 2024-05-17 20-01-55.312 [Info] (PcmStream) State changed: default, state: idle => playing
snapcast  | 2024-05-17 20-01-55.312 [Info] (Server) onStateChanged (default): playing
snapcast  | bluealsa-aplay: [12] D: aplay.c:739: ALSA playback PCM underrun
snapcast  | 2024-05-17 20-01-59.292 [Info] (PcmStream) State changed: default, state: playing => idle
snapcast  | 2024-05-17 20-01-59.292 [Info] (Server) onStateChanged (default): idle
snapcast  | 2024-05-17 20-02-00.352 [Info] (PcmStream) State changed: default, state: idle => playing
snapcast  | 2024-05-17 20-02-00.352 [Info] (Server) onStateChanged (default): playing
snapcast  | bluealsa-aplay: [12] D: aplay.c:739: ALSA playback PCM underrun
snapcast  | 2024-05-17 20-02-01.552 [Info] (PcmStream) State changed: default, state: playing => idle
snapcast  | 2024-05-17 20-02-01.552 [Info] (Server) onStateChanged (default): idle
snapcast  | 2024-05-17 20-02-02.372 [Info] (PcmStream) State changed: default, state: idle => playing
snapcast  | 2024-05-17 20-02-02.372 [Info] (Server) onStateChanged (default): playing
snapcast  | 2024-05-17 20-02-59.192 [Info] (PcmStream) State changed: default, state: playing => idle
snapcast  | 2024-05-17 20-02-59.192 [Info] (Server) onStateChanged (default): idle
snapcast  | bluealsa-aplay: [12] D: aplay.c:739: ALSA playback PCM underrun
snapcast  | 2024-05-17 20-03-00.352 [Info] (PcmStream) State changed: default, state: idle => playing
snapcast  | 2024-05-17 20-03-00.352 [Info] (Server) onStateChanged (default): playing

I'm streaming from a smartphone via bluetooth adapter -> bluez-alsa -> alsa loopback in -> alsa loopback out -> snapserver alsa stream