Snapcast: snapclient crash + high cpu usage with 0.19 (not seen with 0.18.1)

[apurohit]

Hi,

I am running a snapclient on an odroid xu4 (armhf) that connects to a snapserver (running mopidy on an x86 server). My client is wired-connected to a router running as a 'wireless bridge'.

This isn't a very dependable connection so I have set the snapserver 'buffer' to 3 seconds (3000).

When running 0.18.1 this setup (on the client) takes up about 12% cpu for all 4 threads and works with virtually no drops.

When I upgraded v 0.19, the cpu usage on one of the 4 snapclient threads is almost always pegged to 100% and snapclient terminates with the following error every 3-5 minutes:

terminate called after throwing an instance of 'std::bad_alloc'

switching back to 0.18.1, I don't see the error and snapclient doesn't crash (note that snapserver is still at 0.19).

[badaix]

Can you post a log? Preferably with --debug?
Please test also the current develop branch.
Can you try to debug it or make your device ssh accessible over the internet?

[apurohit]

Attached debug log. I hope it helps:

snapclient_err.txt

[apurohit]

I couldn't kick off a build as submodule update fails because git.xiph.org seems to be down.

[badaix]

you don't need the submodules

[badaix]

Nothing special in the log. Can you run the develop build in gdb?
You can also make the odroid available over internet or send me one, so that I can fix it.

[apurohit]

I'm not familiar with gdb but I did do a full build and install on the odroid (last commit ID: bfbd9e05a7) CPU usage is also not 100% it hovers around 80-90% on 1 cpu (of the 8).

Also for some reason --debug didn't output debug at all (only Info):

odroid@odroid:~$ /usr/bin/snapclient --debug --user odroid:odroid --soundcard pulse --host 192.168.xx.xx
2020-05-06 11-26-05.862 [Info] (main) Latency: 0
2020-05-06 11-26-05.868 [Notice] (start) Connected to 192.168.xx.xx
2020-05-06 11-26-05.868 [Info] (getMacAddress) My MAC: ":::::", socket: 6
2020-05-06 11-26-06.016 [Info] (onMessageReceived) ServerSettings - buffer: 3000, latency: 0, volume: 100, muted: 0
metadata:{"STREAM":"default"}
2020-05-06 11-26-06.017 [Info] (onMessageReceived) Codec: flac
2020-05-06 11-26-06.017 [Notice] (state) sampleformat: 48000:16:2
2020-05-06 11-26-06.028 [Info] (Alsa) frames: 1440
2020-05-06 11-26-06.030 [Info] (Alsa) Resizing buffer from 0 to 23040
2020-05-06 11-26-06.030 [Info] (Stream) no chunks available
2020-05-06 11-26-06.031 [Info] (Alsa) Failed to get chunk
2020-05-06 11-26-06.391 [Info] (worker) diff to server [ms]: 1.58873e+12
terminate called after throwing an instance of 'std::bad_alloc'
what(): std::bad_alloc
Aborted

Sorry I can't send you an odroid or put this one on the internet. But I do intend to try without my flaky wireless bridge setup. I'll connect a regular usb wifi adapter directly to the odroid and check if that helps.

[badaix]

in develop branch you must use --logfilter debug.
I could open a new branch and try some things there, so that you could compile and test the changes. Maybe we can fix the problem in two or three iterations.

[badaix]

Update: I played a bit and removed the function call to snd_pcm_wait, which is used to wait for the device to be ready to process new data. Without this call I managed to get high CPU usage and a std::bad_alloc. So maybe on your system snd_pcm_wait signals that the device is ready without actually being ready.
In the develop branch I've added an additional check that could fix your problem.
Please update, try and report back :)

[apurohit]

I will try tonight and get back to you. Meanwhile my wifi adapter setup (instead of the wired to router in wireless-bridge mode) setup didn't work as the driver install failed.

So I'll try the following 2 things:
(1) latest develop with no network change and
(2) v19 wired to main router (to eliminate wifi as a potential trouble point)

and post an update here.

[badaix]

Thanks, looking forward for the results.
I think it will not be related to the connectivity, the 0.18 was working for you and I've infact changed "improved" something alsa player related.

[apurohit]

You were right. I just fetched latest (commit id: 860c0e5c) and did a full build and cpu usage is back to 18.1 levels and so far no crashes :)

As far as I am concerned, this one is fixed. Thanks dude!