Snapcast with a beacon scanner doesn't work

[blazejkustra]

Describe the bug
I want to create a multi-room audio (something like this: https://www.home-assistant.io/blog/2016/02/18/multi-room-audio-with-snapcast/). Everything works fine with snapclient on the raspberry and snapserver on ubuntu. I want to also run a simple beacon scanner on raspberryPI to check how close it is to my phone (phone is a beacon emitter). Right after running a node script, snapcast starts to error, when I stop the node script snapcast gets back to normal and I hear the music again.

Steps to Reproduce

1. Run mopidy and snapserver on ubuntu (with snapfifo file)
2. Run snapclient on raspberry - everything works fine till that point
3. Start node scanner for beacons: https://github.com/futomi/node-beacon-scanner

const BeaconScanner = require('node-beacon-scanner');
const scanner = new BeaconScanner();

// Set an Event handler for becons
scanner.onadvertisement = (ad) => {
  console.log(JSON.stringify(ad, null, '  '));
};

// Start scanning
scanner.startScan().then(() => {
  console.log('Started to scan.')  ;
}).catch((error) => {
  console.error(error);
});

4. Right after running node script this error appears "2021-01-12 15-57-06.092 [Info] (Stream) Exception: 0" and music is no longer playing

Environment details

• OS: Raspbian
• Snapcast version 0.22.0
• Installed from a package

Attach logfile if applicable

pi@raspberrypi:~/Desktop $ snapclient --logfilter debug
2021-01-12 15-56-56.376 [Info] (Avahi) (Browser) NEW: service 'Snapcast' of type '_snapcast._tcp' in domain 'local'
2021-01-12 15-56-56.378 [Info] (Avahi) (Browser) CACHE_EXHAUSTED
2021-01-12 15-56-56.380 [Info] (Avahi) Service 'Snapcast' of type '_snapcast._tcp' in domain 'local':
2021-01-12 15-56-56.380 [Info] (Avahi) 	blazej-MacBookAir.local:1704 (192.168.0.142)
2021-01-12 15-56-56.380 [Debug] (Avahi) 	TXT=
2021-01-12 15-56-56.380 [Debug] (Avahi) 	Proto=0
2021-01-12 15-56-56.381 [Debug] (Avahi) 	cookie is 0
2021-01-12 15-56-56.381 [Debug] (Avahi) 	is_local: 0
2021-01-12 15-56-56.381 [Debug] (Avahi) 	our_own: 0
2021-01-12 15-56-56.381 [Debug] (Avahi) 	wide_area: 0
2021-01-12 15-56-56.381 [Debug] (Avahi) 	multicast: 1
2021-01-12 15-56-56.381 [Debug] (Avahi) 	cached: 1
2021-01-12 15-56-56.384 [Info] (Controller) Found server 192.168.0.142:1704
2021-01-12 15-56-56.384 [Info] (Connection) Resolving host IP for: 192.168.0.142
2021-01-12 15-56-56.384 [Info] (Connection) Connecting
2021-01-12 15-56-56.386 [Notice] (Connection) Connected to 192.168.0.142
2021-01-12 15-56-56.387 [Info] (Connection) My MAC: "dc:a6:32:4a:01:27", socket: 8
2021-01-12 15-56-56.532 [Debug] (Connection) outstanding async_write
2021-01-12 15-56-56.546 [Info] (Controller) ServerSettings - buffer: 1000, latency: 0, volume: 100, muted: 0
metadata:{"STREAM":"default"}
2021-01-12 15-56-56.549 [Info] (Controller) Codec: flac, sampleformat: 48000:16:2
2021-01-12 15-56-56.549 [Info] (Player) Player name: alsa, device: default, description: <none>, idx: 1, sharing mode: unspecified, parameters: <none>
2021-01-12 15-56-56.549 [Info] (Player) Mixer mode: software, parameters: <none>
2021-01-12 15-56-56.549 [Info] (Player) Sampleformat: 48000:16:2, stream: 48000:16:2
2021-01-12 15-56-56.551 [Debug] (Alsa) PCM name: default
2021-01-12 15-56-56.551 [Debug] (Alsa) PCM state: PREPARED
2021-01-12 15-56-56.551 [Debug] (Alsa) channels: 2
2021-01-12 15-56-56.551 [Debug] (Alsa) rate: 48000 bps
2021-01-12 15-56-56.551 [Debug] (Alsa) frames: 720
2021-01-12 15-56-56.551 [Debug] (Alsa) period time: 15000
2021-01-12 15-56-56.551 [Debug] (Player) setVolume exp with base 10: 1 => 1
2021-01-12 15-56-56.552 [Info] (Stream) no chunks available
2021-01-12 15-56-56.552 [Info] (Alsa) Failed to get chunk
2021-01-12 15-56-56.714 [Info] (Controller) diff to server [ms]: -70023.8
2021-01-12 15-56-57.483 [Debug] (Stream) Silent frames: 972, frames: 1410, age: -20.251
2021-01-12 15-56-57.513 [Debug] (Stats) Chunk: -7	-7	-7	-7	1	29	0
2021-01-12 15-56-58.023 [Debug] (Stats) Chunk: -7	-7	-7	-7	18	29	0
2021-01-12 15-56-59.012 [Debug] (Stats) Chunk: -8	-7	-7	-7	51	30	0
2021-01-12 15-57-00.003 [Debug] (Stats) Chunk: -1	-8	-7	-7	84	30	0
2021-01-12 15-57-01.022 [Debug] (Stats) Chunk: -6	-7	-7	-7	118	30	8
2021-01-12 15-57-02.012 [Debug] (Stats) Chunk: -4	-5	-7	-7	151	30	17
2021-01-12 15-57-03.003 [Debug] (Stats) Chunk: -1	-1	-5	-7	184	29	14
2021-01-12 15-57-04.022 [Debug] (Stats) Chunk: 0	0	-2	-6	218	29	7
2021-01-12 15-57-05.012 [Debug] (Stats) Chunk: 0	0	0	-5	251	29	1
2021-01-12 15-57-06.003 [Debug] (Stats) Chunk: 0	0	0	-3	284	29	0
2021-01-12 15-57-06.092 [Info] (Stream) Exception: 0                         <------------ HERE
2021-01-12 15-57-06.092 [Info] (Alsa) Failed to get chunk
2021-01-12 15-57-06.193 [Debug] (Alsa) Waiting for chunk
2021-01-12 15-57-06.227 [Error] (Alsa) XRUN: Broken pipe
2021-01-12 15-57-06.227 [Debug] (Stream) age > 0: 102ms, dropping old chunks
2021-01-12 15-57-06.228 [Debug] (Stream) age: 102, requested chunk_duration: 60, duration: 24
2021-01-12 15-57-06.228 [Debug] (Stream) age: 78, requested chunk_duration: 60, duration: 24
2021-01-12 15-57-06.228 [Info] (Alsa) Failed to get chunk
2021-01-12 15-57-06.275 [Debug] (Stream) age > 0: 125ms, dropping old chunks
2021-01-12 15-57-06.275 [Debug] (Stream) age: 101, requested chunk_duration: 60, duration: 24
2021-01-12 15-57-06.275 [Info] (Alsa) Failed to get chunk
2021-01-12 15-57-06.333 [Debug] (Stream) age > 0: 159ms, dropping old chunks
2021-01-12 15-57-06.333 [Debug] (Stream) age: 135, requested chunk_duration: 60, duration: 24
2021-01-12 15-57-06.333 [Info] (Alsa) Failed to get chunk
2021-01-12 15-57-06.433 [Debug] (Alsa) Waiting for chunk
2021-01-12 15-57-06.446 [Debug] (Stream) age > 0: 248ms, dropping old chunks
2021-01-12 15-57-06.446 [Debug] (Stream) age: 224, requested chunk_duration: 60, duration: 24
2021-01-12 15-57-06.446 [Debug] (Stream) age: 200, requested chunk_duration: 60, duration: 24
2021-01-12 15-57-06.446 [Info] (Alsa) Failed to get chunk
2021-01-12 15-57-06.546 [Debug] (Stream) age > 0: 300ms, dropping old chunks
2021-01-12 15-57-06.546 [Debug] (Stream) age: 276, requested chunk_duration: 60, duration: 24
2021-01-12 15-57-06.546 [Info] (Alsa) Failed to get chunk
2021-01-12 15-57-06.547 [Debug] (Stream) age > 0: 277ms, dropping old chunks
2021-01-12 15-57-06.548 [Debug] (Stream) age: 254, requested chunk_duration: 60, duration: 24
2021-01-12 15-57-06.548 [Info] (Alsa) Failed to get chunk
2021-01-12 15-57-06.604 [Debug] (Stream) age > 0: 310ms, dropping old chunks
2021-01-12 15-57-06.604 [Debug] (Stream) age: 286, requested chunk_duration: 60, duration: 24
2021-01-12 15-57-06.604 [Info] (Alsa) Failed to get chunk
2021-01-12 15-57-06.704 [Debug] (Alsa) Waiting for chunk
2021-01-12 15-57-06.805 [Debug] (Alsa) Waiting for chunk
2021-01-12 15-57-06.905 [Debug] (Alsa) Waiting for chunk

[badaix]

There is no data received on the client. Is the client connected over WiFI? Maybe your beacon thing interferes with your WiFi.
Can you ping the server from the client while beacon-ing?

[blazejkustra]

Yes, the client is connected over WIFI, and yes I can ping while beaconing. You were right, without a beacon scanner average time for ping is 62ms, while with the scanner it is over 500ms. Beacon scanner interferes with the WIFI but don't know why though. Thanks for the help.

[kingosticks]

There used to a problem with using WiFi and Bluetooth at the same time on the raspberry pi, there were many reports in the rpi forums. And I guess there still is a problem. I thought it was restricted to the pi zero w but I'm not 100% about that.

[blazejkustra]

I connected my RPI 4 to the internet through ethernet cable, it resolved the problem. I would still prefer to use WIFI as it is easier to set up.

[kingosticks]

I believe the problem is specific to the wireless chip on the Raspberry Pi. You can use a USB WiFi dongle or USB Bluetooth dongle to workaround the issue.

Doesn't sound like this is a bug in Snapcast.