badaix / snapcast

Synchronous multiroom audio player
GNU General Public License v3.0
6.21k stars 456 forks source link

Dropouts: onResync, next read < 0 <--> abs(age > 500), Failed to get chunk #1206

Open j-lechner opened 8 months ago

j-lechner commented 8 months ago

Describe the bug I am getting occasional (ca. once per hour) dropouts with Snapcast v0.27.

Any pointers what causes those?

I've tried already different chunk_ms and buffer sizes and switching to wired networking. No luck so far.

Thank you!

Setup: Snapserver running on Raspberry Pi 4 (192.168.178.33)

Config:

source = librespot:///usr/bin/librespot?name=Spotify Study&dryout_ms=2000&devicename=Study&bitrate=320&wd_timeout=7800&normalize=false&autoplay=false&killall=false&params=--volume-ctrl%20fixed

sampleformat = 44100:16:2
codec = pcm
chunk_ms = 40
buffer = 2000

Snapclient running on another Raspberry, audio output via HiFiBerry Digi+ I/O Config: SNAPCLIENT_OPTS="-h 192.168.178.33 -p 1704 -s plughw:CARD=sndrpihifiberry,DEV=0"

Steps to Reproduce

  1. Play music via Spotify Connect
  2. Occasional dropouts

Environment details

Attach logfile if applicable

Snapserver:
Mar 02 01:14:47 Snap snapserver[2917]: onResync (Spotify Study): 1472.83 ms
Mar 02 01:15:16 Snap snapserver[2917]: next read < 0 (Spotify Study): -5.15 ms
...
Mar 02 02:05:09 Snap snapserver[2917]: next read < 0 (Spotify Study): -2.855 ms
Mar 02 02:05:24 Snap snapserver[2917]: next read < 0 (Spotify Study): -8.407 ms
Mar 02 02:06:24 Snap snapserver[2917]: onResync (Spotify Study): 686.012 ms
...
Mar 02 02:53:12 Snap snapserver[2917]: next read < 0 (Spotify Study): -2.188 ms
Mar 02 02:54:37 Snap snapserver[2917]: next read < 0 (Spotify Study): -4.584 ms
Mar 02 02:55:03 Snap snapserver[2917]: onResync (Spotify Study): 687.193 ms
...
Mar 02 02:50:07 Snap snapserver[2917]: onResync (Spotify Study): 763.587 ms
Mar 02 02:50:32 Snap snapserver[2917]: next read < 0 (Spotify Study): -13.008 ms
Mar 02 02:50:57 Snap snapserver[2917]: next read < 0 (Spotify Study): -1.362 ms
Mar 02 02:51:12 Snap snapserver[2917]: next read < 0 (Spotify Study): -4.065 ms
Mar 02 02:51:27 Snap snapserver[2917]: next read < 0 (Spotify Study): -6.928 ms

Snapclient:
Mar 02 01:14:48 DietPi snapclient[515]: abs(age > 500): 1564313
Mar 02 01:14:48 DietPi snapclient[515]: Failed to get chunk
Mar 02 02:06:26 DietPi snapclient[515]: abs(age > 500): 775689
Mar 02 02:06:26 DietPi snapclient[515]: Failed to get chunk
Mar 02 02:50:09 DietPi snapclient[515]: abs(age > 500): 854665
Mar 02 02:50:09 DietPi snapclient[515]: Failed to get chunk
Mar 02 02:55:04 DietPi snapclient[515]: abs(age > 500): 777567
Mar 02 02:55:04 DietPi snapclient[515]: Failed to get chunk
J1810Z commented 7 months ago

I have a similar issues only that I use USB audio and the dropouts happen at least once per minute.

I already experimented with moving the server to the same raspberry as the client (to exclude network issues) or into a separate VM. The issue also occurs independently whether I stream directly via spotify connect to librespot on the server or whether I use music assistant to stream to the server.

The dropouts also occur player independent, i.e., also if I stream to Snapweb instead of the snapclient raspberrypi.