unstable playback

[rcmcronny]

Client: Raspberry Pi Zero + raspbian buster + snapclient 0.20 Server: Ubuntu 20.04 amd64 + snapserver 0.20

Hi,

i am using snapcast since a long time (0.12 or so) it worked, sometimes there were short drop outs, but they were seldom and that was ok. Mostly a reboot of the client helped to get it working for many days. Since 0.20 now, i do not get a reliable playback. I have 2 clients atm (the volumio client shows a seg fault, so i disabled it for now) This log is from a raspberry pi zero with hdmi output (analog adapter to a simple speaker (Bathroom)).

snapclient.log

[info: i redacted the server host IP and the client mac]

On the " (Stream) pMiniBuffer->full() && (abs(pMiniBuffer->mean()) > 50)" lines the sound drops and comes back, sometimes i can play more, sometimes it happens on every some seconds. I tested it with urandom now, to rule out mpd -> pulse fifo and it happens also. The ntp time is set and correct on all clients. Its wifi,so i increased the buffer form 750ms to now 2000ms but all does not help. I tried also to change the format, this also does not help. Sometimes there is a "(Alsa) failed to get chunk message right befor the "Stream pMini ..." line.

I know, somewhere was the info, what the Stats line and the columns means, but i dont found it :)

@badaix Any hints on what to do to get it fixed ?

(The other raspi is also a pi zero with a hifibery dac hat, there it happens also, but i have no log atm for it)

Many Thanks Ronny

[badaix]

Looks like the HDMI is unreliably reporting the playout time (framesDelay) in alsa_player.cpp

int result = snd_pcm_avail_delay(handle_, &framesAvail, &framesDelay);

Can you uncomment lines 532 and 534 and create another log?

        // LOG(TRACE, LOG_TAG) << "res: " << result << ", framesAvail: " << framesAvail << ", delay: " << framesDelay << ", frames: " << frames_ << "\n";
        chronos::usec delay(static_cast<chronos::usec::rep>(1000 * (double)framesDelay / format.msRate()));
        // LOG(TRACE, LOG_TAG) << "delay: " << framesDelay << ", delay[ms]: " << delay.count() / 1000 << ", avail: " << framesAvail << "\n";

Maybe you can use a different audio device, what is your snapclient -l output? And don't worry about posting private IPs, my server's IP is 192.168.0.3 :)

[rcmcronny]

@badaix thanks, i will try to get some time to rebuild it with the 2 lins uncommented.

snapcast -l output shows:

0: null
Discard all samples (playback) or generate zero samples (capture)

1: default:CARD=b1
bcm2835 HDMI 1, bcm2835 HDMI 1
Default Audio Device

2: sysdefault:CARD=b1
bcm2835 HDMI 1, bcm2835 HDMI 1
Default Audio Device

3: dmix:CARD=b1,DEV=0
bcm2835 HDMI 1, bcm2835 HDMI 1
Direct sample mixing device

4: dsnoop:CARD=b1,DEV=0
bcm2835 HDMI 1, bcm2835 HDMI 1
Direct sample snooping device

5: hw:CARD=b1,DEV=0
bcm2835 HDMI 1, bcm2835 HDMI 1
Direct hardware device without any conversions

6: plughw:CARD=b1,DEV=0
bcm2835 HDMI 1, bcm2835 HDMI 1
Hardware device with all software conversions

7: default:CARD=Headphones
bcm2835 Headphones, bcm2835 Headphones
Default Audio Device

8: sysdefault:CARD=Headphones
bcm2835 Headphones, bcm2835 Headphones
Default Audio Device

9: dmix:CARD=Headphones,DEV=0
bcm2835 Headphones, bcm2835 Headphones
Direct sample mixing device

10: dsnoop:CARD=Headphones,DEV=0
bcm2835 Headphones, bcm2835 Headphones
Direct sample snooping device

11: hw:CARD=Headphones,DEV=0
bcm2835 Headphones, bcm2835 Headphones
Direct hardware device without any conversions

12: plughw:CARD=Headphones,DEV=0
bcm2835 Headphones, bcm2835 Headphones
Hardware device with all software conversions

[badaix]

Please try to start Snapclient with -s 5, maybe this will work better

[rcmcronny]

Tried -s 5 and -s 6, same behavior. I ordered a extra usb soundcard, but with it, its the same, no matter what card i choose. Then i tried snapclient 0.18.1 and 0.19, but also the same. I will try to build a debug version at the weekend and search an old pi, perhaps this is pi zero w related, this worked some times ago really flawless.

[Adsbom]

Hi Guys, thought I'd throw my observations in the ring given that I've been seeing this same issue. My setup: Server: Laptop running Ubuntu 20.04.1 amd64 + Mopidy + Snapserver 0.20 Clients: Laptop w/ Snapclient 0.20 - audio output via 3.5mm jack RPi 3 + Raspbian & HifiBerry DAC w/ Snapclient 0.20 Mopidy pipes audio to fifos which is picked up by Snapserver.

As mentioned above, audio drops on the "pMiniBuffer->full() && (abs(pMiniBuffer->mean()) > 50)" lines in the log, for me this has happened both with and without external clients, i.e. when running the server and client locally on the same machine the drop outs still occur. Decreasing the buffer and chunk sizes seemed to help decrease the frequency of the drop outs, though they still occur quite often. An additional thing that I noticed when watching the logs for the Snapserver and Snapclient is that the "pMiniBuffer" drop out occurs a fraction of a second (on average ~0.7s) after the "onResync" from Snapserver. I've attached a log from the server and client demonstrating this. SnapServerLog.txt SnapClientLog.txt

I can't admit to being proficient in coding or linux systems, but happy to help in whatever capacity I can.

[badaix]

@Adsbom you have buffer underruns in your pipe:

2020-08-02 15-06-27.524 [Info] (onResync) onResync (default): 78 ms
2020-08-02 15-06-32.863 [Info] (onResync) onResync (default): 79 ms
2020-08-02 15-06-43.403 [Info] (onResync) onResync (default): 79 ms
2020-08-02 15-06-48.751 [Info] (onResync) onResync (default): 78 ms
2020-08-02 15-06-54.013 [Info] (do_read) next read < 0 (default): -0.983 ms
2020-08-02 15-07-04.491 [Info] (onResync) onResync (default): 79 ms
2020-08-02 15-07-09.831 [Info] (onResync) onResync (default): 79 ms
2020-08-02 15-07-15.171 [Info] (onResync) onResync (default): 79 ms
2020-08-02 15-07-35.370 [Info] (onResync) onResync (default): 79 ms
2020-08-02 15-07-51.103 [Info] (onResync) onResync (default): 62 ms
2020-08-02 15-08-06.843 [Info] (onResync) onResync (default): 79 ms

This means that it took 78ms longer to read the next 10ms audio chunk from the pipe. Are you sure that Mopidy is configured with 48000Hz? If it feeds audio in with 44100Hz while you're reading at 48000Hz such underruns could occur.

[Adsbom]

@badaix thanks for the suggestion but I'm pretty sure I have that part of Mopidy configured right, this is the output line in my config: output = audioresample ! audioconvert ! audio/x-raw,rate=48000,channels=2,format=S16LE ! wavenc ! filesink location=/tmp/snapfifo I had read the 48000Hz / 44100Hz mismatch could cause this issue so it was one of the things I checked. Apart from looking at the config the only other thing that I have done to try and verify that Mopidy is actually doing what the config says is to change it to 44100Hz which exhibits the same audio drop problem along with a change in pitch of the music.

[badaix]

Does it also happen when you use the file plugin (stream = file:///home/user/Music/Some%20wave%20file.wav?name=File) or feed some other data to the pipe, e.g. sudo cat /dev/urandom > /tmp/snapfifo or cat /home/user/Music/SomeWaveFile.wav> /tmp/snapfifo I heard that the gstreamer filesink sometimes causes trouble when feeding a named pipe.

[Adsbom]

Haven't tried with the file plugin, but it does also happen when using sudo cat /dev/urandom or with a wave file (sampled at 48kHz).

[rcmcronny]

@badaix I have not chance to rebuild it for rasberry os ( raspbian). But did the chance to make a minimal SnapOS Build (2020.05.01 base) for me, to rule out most. I attach 3 logs (snapos-1 and 2 are before the patch was active (i think) and 3 is with the patch surely applied).

1: snapos-log1.txt 2: snapos-log2.txt 3: snapos-log3.txt

I also used my windows client to play and there it happens also, this seems so more server related perhaps ? (Its a ubuntu 20.04 KVM (with 2 vcpu and 1G memory (for 3 mpd instances [which 1 is used atm] and snapcast server only)

[badaix]

@rcmcronny the logs have trace level, you must enable them with --logfilter *:trace or less verbose --logfilter *:debug,Alsa:trace. If it's the server, then the server logs would be interesting. @Adsbom Try the file plugin, it will not use a pipe. Maybe you both have the same problem with Ubuntu 20.04 ant it's pipe configuration.

[rcmcronny]

@badaix ahhh, that makes sense, sorry for not interpreting it correctly, i did a quick run remotely and here is a log with the lines. snapos.log

For the server, i will try to get a log (trace i think should be the best option ?)

EDIT: and here is the snapserver log (both runs were not at the same time) snapserver.log

PA-BAD is the stream from the other logs Perhaps you spot something

[Adsbom]

@badaix I think you're on to something, the file plugin works fine for me so it could very well be all in the fifos pipe. I've spent some time setting up the tcp stream and haven't had any drop outs so far. Really appreciate your help in sorting this out!

@rcmcronny In case you were also running a filesink the changes I made to get the tcp plugin working were: mopidy.conf output = audioresample ! audioconvert ! audio/x-raw,rate=48000,channels=2,format=S16LE ! wavenc ! tcpclientsink host=127.0.0.1 port=4953

snapserver.conf stream = tcp://127.0.0.1?name=mopidy&port=4953

[badaix]

Can you please test the development snapshot from the automated build? This will log the size of the pipe. Maybe the default size has changed. The server logline will look like this:

2020-08-08 15-16-08.622 [Info] (PipeStream) Stream: MPD, connect to pipe: /tmp/snapfifo, fd: 9, pipe size: 65536

As a bonus, the development snapshot will also ship snapweb with an integrated web player. The URL is <hostname or IP of the snapserver>:1780

[Adsbom]

@badaix Yep no worries, installed the v0.21 snapserver and looks like that line matches what I have: Aug 10 21:24:53 laptop-HTPC snapserver[3381]: Stream: default, connect to pipe: /tmp/snapfifo, fd: 17, pipe size: 65536

[badaix]

Ok, thanks, same pipe size as on my system. You're running on 4 cores, so it should not be a load problem (if flac encoding of a single chunk would take longer, this could also cause such message [Info] (onResync) onResync (default): 79 ms). Can you compile the server? Then you could test to raise the "resync tolerance" in posix_stream.cpp to some higher number (e.g. 100ms):

static constexpr auto kResyncTolerance = 50ms;

[Adsbom]

Hey @badaix, took me a little while to get my head around compiling the server but managed it with the increase to the resync tolerance (100ms as suggested). Seems to have got rid of the audio drop-outs in the testing I've done so far, logs are attached for reference. By increasing the resync is this allowing more time for the read-write to the fifo, or is it doing something else? CompiledSnapServerLog.txt CompiledSnapClientLog.txt

[platsch]

I am facing the same problem. My setup: snapcast server on BananaPi running Armbian 5.4.20-sunxi several clients (Ubuntu 18.04 4.15.0-112-generic, android devices)

The latest snapcast server release runs, but frequently produces (Stream) pMiniBuffer->full() && (abs(pMiniBuffer->mean()) > 50): errors. Running the server on a laptop with an 18.04 Ubuntu works perfectly.

I followed @badaix advise and compiled the server on my Pi with kResyncTolerance = 100ms; and the problem seems to be gone or at least significantly diminished. However, I still see a lot of

[Info] (do_read) next read < 0 (default): -0.789 ms

messages from the server, probably related to #542. Maybe the old BananaPi hardware is just too outdated :-(

[badaix]

@rcmcronny interesting. All of your three pipes "stuck" at the same time for the same duration:

2020-08-06 10-22-56.346 [Info] (onResync) onResync (PA-MAIN): 86 ms
2020-08-06 10-22-56.347 [Info] (onResync) onResync (PA-BAD): 86 ms
2020-08-06 10-22-56.347 [Info] (onResync) onResync (PA-KUECHE): 86 ms

2020-08-06 10-22-57.301 [Info] (onResync) onResync (PA-MAIN): 564 ms
2020-08-06 10-22-57.302 [Info] (onResync) onResync (PA-KUECHE): 560 ms
2020-08-06 10-22-57.302 [Info] (onResync) onResync (PA-BAD): 565 ms

2020-08-06 10-23-01.608 [Info] (onResync) onResync (PA-MAIN): 275 ms
2020-08-06 10-23-01.608 [Info] (onResync) onResync (PA-KUECHE): 275 ms
2020-08-06 10-23-01.609 [Info] (onResync) onResync (PA-BAD): 275 ms

2020-08-06 10-23-06.489 [Info] (onResync) onResync (PA-MAIN): 111 ms
2020-08-06 10-23-06.490 [Info] (onResync) onResync (PA-KUECHE): 111 ms
2020-08-06 10-23-06.490 [Info] (onResync) onResync (PA-BAD): 111 ms

2020-08-06 10-23-09.696 [Info] (onResync) onResync (PA-MAIN): 56 ms
2020-08-06 10-23-09.696 [Info] (onResync) onResync (PA-BAD): 74 ms
2020-08-06 10-23-09.697 [Info] (onResync) onResync (PA-KUECHE): 56 ms

@rcmcronny @platsch @Adsbom : Please try the new alsa input plugin as described in #674 Snapcast v0.21 can capture audio from alsa, and to capture the output of a player, an alsa loopback device can be used:

1. setup the alsa loopback device by loading the kernel module:

   sudo modprobe snd-aloop

2. the loopback device should show up in aplay -l

   aplay -l
   **** List of PLAYBACK Hardware Devices ****
   card 0: Loopback [Loopback], device 0: Loopback PCM [Loopback PCM]
   Subdevices: 8/8
   Subdevice #0: subdevice #0
   Subdevice #1: subdevice #1
   Subdevice #2: subdevice #2
   Subdevice #3: subdevice #3
   Subdevice #4: subdevice #4
   Subdevice #5: subdevice #5
   Subdevice #6: subdevice #6
   Subdevice #7: subdevice #7
   card 0: Loopback [Loopback], device 1: Loopback PCM [Loopback PCM]
   Subdevices: 8/8
   Subdevice #0: subdevice #0
   Subdevice #1: subdevice #1
   Subdevice #2: subdevice #2
   Subdevice #3: subdevice #3
   Subdevice #4: subdevice #4
   Subdevice #5: subdevice #5
   Subdevice #6: subdevice #6
   Subdevice #7: subdevice #7
   card 1: Intel [HDA Intel], device 0: CX20561 Analog [CX20561 Analog]
   Subdevices: 1/1
   Subdevice #0: subdevice #0
   card 1: Intel [HDA Intel], device 1: CX20561 Digital [CX20561 Digital]
   Subdevices: 1/1
   Subdevice #0: subdevice #0
   card 2: CODEC [USB Audio CODEC], device 0: USB Audio [USB Audio]
   Subdevices: 0/1
   Subdevice #0: subdevice #0

   On my system it's card 0 with devices 0 and 1, each having 8 subdevices. You can address them with hw:<card idx>,<device idx>,<subdevice num>, i.e. hw:0,0,0. If a process plays audio using hw:0,0,x, then this audio is looped back to hw:0,1,x, so

3. Configure your player to use a loopback device.

For mopidy (gstreamer) it should be something like this (not tested):

output = audioresample ! audioconvert ! audio/x-raw,rate=48000,channels=2,format=S16LE ! wavenc ! alsasink device=hw:0,0,0

For mpd: in mpd.conf

audio_output_format            "48000:16:2"
audio_output {
        type            "alsa"
        name            "My ALSA Device"
        device          "hw:0,0,0"      # optional
#       auto_resample   "no"
#       mixer_type      "hardware"      # optional
#       mixer_device    "default"       # optional
#       mixer_control   "PCM"           # optional
#       mixer_index     "0"             # optional
}

4. Configure Snapserver to capture the loopback device:

[stream]
stream = alsa://?name=SomeName&sampleformat=48000:16:2&device=hw:0,1,0

This is my default setup for some two weeks now (using MPD, never having resync problems, neither with pipe, nor with alsa). But I hope that this will make usage of Mopidy more stable, as the filesink seems cause some trouble for many users, and the pipe for some users (i.e. you).

[platsch]

Thanks for your help. After spending a lot of time on the audio setup I updated my OS to the current focal release (Armbian 5.7.15-sunxi) and with that the problem seems to have vanished, so I can't reproduce anymore.

[badaix]

closing due to inactivity

[rcmcronny]

@badaix sorry, i was somewhat busy trying things. I got it better , but not yet perfect, i hoped, you release the 0.21 version, to rebuild the snapos image :) i hope to get more time at the weekend to test some things out, will post again then.

[badaix]

did you try the new alsa plugin? I'm waiting for some more users to play around with it until I release the v0.21

[rcmcronny]

did you try the new alsa plugin? I'm waiting for some more users to play around with it until I release the v0.21

Yes, i tried. But as I also use pulseaudio (to inject a remote tts system to all snapcastclients) this was not successful for me. MPD complaint ablout "device not found" but it was there, the search revealted, that this may be caused by pulseaudio. I need to get into detail, on how to change all parts to use the also plugin, perhaps i can ditch pulseaudio and use alsa and for the announcement the tcp plugin.

[rcmcronny]

Short Update: I tested since some days and missed the pulseaudio environment variable (latency set to 60ms) since i set this, things got really better. Another major part seems to be the kvm host, which has had some io load, dont know where it comes from, but it solved. Please leave open, i want to check some more days. in the last days, i have had sometimes rare short drops (for about 3-5 seconds no sound) and i hope to catch more details on what was / is the issue here, perhaps related.

[Adsbom]

did you try the new alsa plugin? I'm waiting for some more users to play around with it until I release the v0.21

I have made an attempt at getting the alsasink to work in Mopidy but so far haven't had any success. Created the loopback device with the sudo modprobe snd-aloop command, pointed Mopidy to card 0 and Snapserver to card 1 (both subdevice 0), but couldn't get Mopidy to play anything. At this point I'm not sure where this issue lies, I assume Mopidy given that you have tested the Snapserver side with MPD. Regardless, I will continue the troubleshooting over the next few days and report back.

[rcmcronny]

@Adsbom thats not the way, you must use (for example)
hw<CARDID>,<DEVICE>,<SUBSTREAM> CARDID is the cardid of alsa DEVICE is 0 for input and 1 for output Substreams are the pairs for the 8 streams (0-7) Device 0 Substream 0 input goes to output of device 1, substream 0

The first of the 8 in/output pairs is therefore:

input:   hwX,0,0
output:  hwX,1,0

X ist the card id of the snd Modul

So you should change your config to the SAME card, but different devices (0 / 1) and substream 0 for example to test ;) Different cards will not work.

HTH Ronny

[Adsbom]

@rcmcronny Apologies that was a typo on my part, I should have said device 0 and device 1 (not card). The alsa loopback was card 1 on my system so I was using: input: hw1,0,0 output: hw1,1,0 Sorry for the confusion!

[badaix]

Just saw that the description regarding alsa setup was actually wrong, it's corrected now, and also described in Configuration

I've now tested with mopidy and found another issue in the documentation: the wavenc must be removed, so not

output = audioresample ! audioconvert ! audio/x-raw,rate=48000,channels=2,format=S16LE ! wavenc ! alsasink device=hw:0,0,0

but

output = audioresample ! audioconvert ! audio/x-raw,rate=48000,channels=2,format=S16LE ! alsasink device=hw:0,0,0

[Adsbom]

@badaix That corrected output line gets Mopidy to work for me, however I have come up against a weird problem, the systemctl version of snapserver refuses to start when using the alsasink, though if I run snapserver as a terminal command it works fine. I have attached the output from the systemctl status command in case that gives any clues as to why this is happening. SnapServerAlsaSink.txt

[badaix]

Is something useful logged into syslog?

[Adsbom]

Sorry didn't understand how the syslog worked. I've found a repeating error that the audio card that I've referenced in the stream can't be opened, which after a number of attempts cause the process to be killed. However, the output from aplay -l shows the index that I've used is indeed correct, and the terminal snapserver instance also works fine (output/logs attached). Would this suggest that it is a permissions issue? SnapServerAlsaSink.txt aplay.txt SnapTerminalOutput.txt

[badaix]

Oh, I think you're right. The server must have "audio" permissions. The debian package will create the snapserver user and add him to the audio group. But the user will not be created if he already exists (as in case of an update). You can either apt remove snapserver and install again or add the user manually to the audio group: adduser snapserver audio

[badaix]

The v0.21.0 has been released today an it will add the snapserver user to the audio group also for an update installation.

[Adsbom]

Thanks @badaix, can confirm the adduser snapserver audio command did the trick. Had a couple of extra hurdles to jump to avoid having the creation of the alsa loopback break my audio hardware on boot, but have a workaround now and can confirm that the alsasink option is working with mopidy.

[rcmcronny]

@badaix for me it really works better, there are sometimes drops, but it seems this is KVM host related.

One thing came into my mind, as a searched through the logfiles of my "self snapos build client"

2020-09-17T12:14:25+02:00 snapcast snapclient[210]: Received signal 15: Terminated
2020-09-17T12:14:25+02:00 snapcast snapclient[210]: daemon terminated.
2020-09-17T12:14:50+02:00 snapcast snapclient[206]: daemonizing
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: daemon started
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: Resolving host IP for: 10.0.0.51
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: Connecting
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: Connected to 10.0.0.51
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: My MAC: "b8:27:eb:80:97:04", socket: 7
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: ServerSettings - buffer: 1000, latency: 0, volume: 74, muted: 0
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: Codec: flac, sampleformat: 48000:16:2
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: Player name: alsa, device: default:CARD=sndrpihifiberry, description: snd_rpi_hifiberry_dac, HifiBerry DAC HiFi pcm5102a-hifi-0
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: Default Audio Device, idx: 1, sharing mode: unspecified
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: Mixer mode: software, parameters: <none>
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: Sampleformat: 48000:16:2, stream: 48000:16:2
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: no chunks available
2020-09-17T12:14:50+02:00 snapcast snapclient[207]: Failed to get chunk
2020-09-17T12:14:51+02:00 snapcast snapclient[207]: diff to server [ms]: 6.83821e+07
2020-09-17T12:14:55+02:00 snapcast snapclient[207]: No chunk received for 5000ms. Closing ALSA.
2020-09-17T12:45:11+02:00 snapcast snapclient[207]: Time sync request failed: Connection timed out
2020-09-17T12:45:11+02:00 snapcast snapclient[207]: Error reading message header of length 0: Operation canceled
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: Resolving host IP for: 10.0.0.51
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: Connecting
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: Connected to 10.0.0.51
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: My MAC: "b8:27:eb:80:97:04", socket: 7
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: ServerSettings - buffer: 1000, latency: 0, volume: 74, muted: 0
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: Codec: flac, sampleformat: 48000:16:2
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: Player name: alsa, device: default:CARD=sndrpihifiberry, description: snd_rpi_hifiberry_dac, HifiBerry DAC HiFi pcm5102a-hifi-0
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: Default Audio Device, idx: 1, sharing mode: unspecified
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: Mixer mode: software, parameters: <none>
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: Sampleformat: 48000:16:2, stream: 48000:16:2
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: no chunks available
2020-09-17T12:45:12+02:00 snapcast snapclient[207]: Failed to get chunk
2020-09-17T12:45:13+02:00 snapcast snapclient[207]: diff to server [ms]: 6.83821e+07
2020-09-17T12:45:17+02:00 snapcast snapclient[207]: No chunk received for 5000ms. Closing ALSA.

Mostly these 2 lines

2020-09-17T12:45:11+02:00 snapcast snapclient[207]: Time sync request failed: Connection timed out
2020-09-17T12:45:11+02:00 snapcast snapclient[207]: Error reading message header of length 0: Operation canceled

Is this normal behavior ? That this happens after some time (have no older remote logs atm) but i think 30-60 min sometimes 1-3h

EDIT: Here is the server side log

Sep 17 12:15:13 ubuntu-music snapserver[605]: StreamServer::NewConnection: 10.0.6.94
Sep 17 12:15:13 ubuntu-music snapserver[605]: Hello from b8:27:eb:80:97:04, host: snapcast, v0.21.0, ClientName: Snapclient, OS: SnapOS RoBo Buil
d (Buildroot 2020.08), Arch: armv6l, Protocol version: 2
Sep 17 12:35:12 ubuntu-music snapserver[605]: next read < 0 (PA-KUECHE): -48.683 ms
Sep 17 12:35:12 ubuntu-music snapserver[605]: next read < 0 (PA-KUECHE): -28.873 ms
Sep 17 12:35:12 ubuntu-music snapserver[605]: next read < 0 (PA-KUECHE): -8.966 ms
Sep 17 12:35:12 ubuntu-music snapserver[605]: next read < 0 (PA-BAD): -48.975 ms
Sep 17 12:35:12 ubuntu-music snapserver[605]: next read < 0 (PA-BAD): -29.093 ms
Sep 17 12:35:12 ubuntu-music snapserver[605]: next read < 0 (PA-BAD): -9.158 ms
Sep 17 12:35:12 ubuntu-music snapserver[605]: next read < 0 (PA-MAIN): -38.028 ms
Sep 17 12:35:12 ubuntu-music snapserver[605]: next read < 0 (PA-MAIN): -18.115 ms
Sep 17 12:37:12 ubuntu-music snapserver[605]: next read < 0 (PA-BAD): -0.627 ms
Sep 17 12:37:12 ubuntu-music snapserver[605]: next read < 0 (PA-KUECHE): -1.215 ms
Sep 17 12:54:23 ubuntu-music snapserver[605]: Error reading message header of length 0: End of file
Sep 17 12:54:23 ubuntu-music snapserver[605]: onDisconnect: b8:27:eb:80:97:04
Sep 17 12:55:06 ubuntu-music snapserver[605]: onResync (PA-MAIN): 85 ms
Sep 17 12:55:17 ubuntu-music snapserver[605]: StreamServer::NewConnection: 10.0.6.94
Sep 17 12:55:18 ubuntu-music snapserver[605]: Hello from b8:27:eb:80:97:04, host: snapcast, v0.21.0, ClientName: Snapclient, OS: SnapOS RoBo Build (Buildroot 2020.08), Arch: armv6l, Protocol version: 2
Sep 17 14:14:25 ubuntu-music snapserver[605]: Error reading message header of length 0: End of file
Sep 17 14:14:25 ubuntu-music snapserver[605]: onDisconnect: b8:27:eb:80:97:04
Sep 17 14:14:50 ubuntu-music snapserver[605]: StreamServer::NewConnection: 10.0.6.94
Sep 17 14:14:50 ubuntu-music snapserver[605]: Hello from b8:27:eb:80:97:04, host: snapcast, v0.21.0, ClientName: Snapclient, OS: SnapOS RoBo Build (Buildroot 2020.08), Arch: armv6l, Protocol version: 2
Sep 17 14:45:11 ubuntu-music snapserver[605]: Error reading message header of length 0: End of file
Sep 17 14:45:11 ubuntu-music snapserver[605]: onDisconnect: b8:27:eb:80:97:04
Sep 17 14:45:12 ubuntu-music snapserver[605]: StreamServer::NewConnection: 10.0.6.94
Sep 17 14:45:12 ubuntu-music snapserver[605]: Hello from b8:27:eb:80:97:04, host: snapcast, v0.21.0, ClientName: Snapclient, OS: SnapOS RoBo Build (Buildroot 2020.08), Arch: armv6l, Protocol version: 2
Sep 17 15:02:35 ubuntu-music snapserver[605]: Error reading message header of length 0: End of file
Sep 17 15:02:35 ubuntu-music snapserver[605]: onDisconnect: b8:27:eb:53:f5:6a
Sep 17 15:02:36 ubuntu-music snapserver[605]: StreamServer::NewConnection: 10.0.6.84
Sep 17 15:02:36 ubuntu-music snapserver[605]: Hello from b8:27:eb:53:f5:6a, host: pi-zero-w1, v0.21.0, ClientName: Snapclient, OS: Raspbian GNU/Linux 10 (buster), Arch: armv6l, Protocol version: 2
Sep 17 15:11:10 ubuntu-music snapserver[605]: Error reading message header of length 0: End of file
Sep 17 15:11:10 ubuntu-music snapserver[605]: onDisconnect: b8:27:eb:53:f5:6a
Sep 17 15:11:12 ubuntu-music snapserver[605]: StreamServer::NewConnection: 10.0.6.84
Sep 17 15:11:12 ubuntu-music snapserver[605]: Hello from b8:27:eb:53:f5:6a, host: pi-zero-w1, v0.21.0, ClientName: Snapclient, OS: Raspbian GNU/Linux 10 (buster), Arch: armv6l, Protocol version: 2
Sep 17 15:12:09 ubuntu-music snapserver[605]: Error reading message header of length 0: End of file
Sep 17 15:12:09 ubuntu-music snapserver[605]: onDisconnect: b8:27:eb:53:f5:6a
Sep 17 15:12:12 ubuntu-music snapserver[605]: StreamServer::NewConnection: 10.0.6.84
Sep 17 15:12:12 ubuntu-music snapserver[605]: Hello from b8:27:eb:53:f5:6a, host: pi-zero-w1, v0.21.0, ClientName: Snapclient, OS: Raspbian GNU/Linux 10 (buster), Arch: armv6l, Protocol version: 2

[badaix]

seems you have connectivity issues. Ok to close?

[rcmcronny]

The issue is, wifi is stable, no messages or ping issues, really not discoverable, whats the issue. This is only visible in the logs. Music plays fine.

But yes, its stable, so i close it :)