pimoroni / pidi-spotify

MIT License
47 stars 12 forks source link

RPI Zero W + Pirate Audio Line-out - unstable sound when changing volume remotely #14

Open alvarovm opened 3 years ago

alvarovm commented 3 years ago

When I am playing a song, and remotely in spotify I change the volume or change the track the sound become unstable, from /var/log/daemon.log I get librespot[2986]: ALSA lib pcm.c:8424:(snd_pcm_recover) underrun occurred as:

Apr 10 08:40:04 audiohat librespot[2986]: [2021-04-10T07:40:04Z INFO  librespot::player_event_handler] Running ["pidi_spotify", "--hook"] with environment variables {"PLAYER_EVENT": "preloading", "TRACK_ID": "4sAwulM4DNcMbKVAcVXZPR"}
Apr 10 08:40:06 audiohat librespot[2986]: ALSA lib pcm.c:8424:(snd_pcm_recover) underrun occurred
Apr 10 08:40:08 audiohat librespot[2986]: ALSA lib pcm.c:8424:(snd_pcm_recover) underrun occurred
Apr 10 08:40:09 audiohat librespot[2986]: [2021-04-10T07:40:09Z INFO  librespot::player_event_handler] Running
["pidi_spotify", "--hook"] with environment variables {"DURATION_MS": "38518", "POSITION_MS": "13112", "TRACK_ID": "6IAetD1HYutD1fihJHWGDL", "PLAYER_EVENT": "playing"}
Apr 10 08:40:10 audiohat librespot[2986]: ALSA lib pcm.c:8424:(snd_pcm_recover) underrun occurred
Apr 10 08:40:11 audiohat librespot[2986]: ALSA lib pcm.c:8424:(snd_pcm_recover) underrun occurred
Apr 10 08:40:12 audiohat librespot[2986]: ALSA lib pcm.c:8424:(snd_pcm_recover) underrun occurred

Any idea how to solve this? Thanks

KSuondProject commented 3 years ago

I'm in the same situation. Finally I managed to make the code works but is unusable. The display has about 40 secs of delay for change the song and during the reproduction every 5 secs I've a signal mute for 1 secs. After a 30 mins the raspberry freeze and I need to hard shutdown unplugging the cable... In this moment for me is unusable the application. I've also tried to incrase the ALSA buffer because I've read somewhere that the buffer underun is due to low assignment memory but it hasn't solved the problem. I hope to retrieve soon a solution because the hardware is so cool but the support of Pimoroni is terrible.

alvarovm commented 3 years ago

The interesting thing is that directly using 'raspotify' without 'pidi_spotify' the audio is pristine, and everything works, except the display of album art, obviously. I suspect 'pidi_spotify' is doing something extra to the alsa connection, maybe developers could help to debug. Also, I noticed that when I poweroff the Pi after using 'pidi_spotify', the screen remains on.

KSuondProject commented 3 years ago

I've replaced the pidi_spotify hook with a simple phyton3 file to test the on-event function of raspotify library and that works very well without any audio problem. When the raspberry is shutdown the 5V power out is on because is connected to the 5V of the USB so the pirate audio board still active (I think...)

The only things that we can do is wait until @Gadgetoid come in our help! 🏳️🏳️

raunraun commented 3 years ago

For me I get this:.

There's a huge difference in execution between manually calling hook.py directly vs. /usr/local/bin/pidi_spotify

pi@raspberrypi:~/pidi-spotify/pidi_spotify $ time PLAYER_EVENT="volume_set" VOLUME=60000 /usr/local/bin/pidi_spotify --hook

real    0m6.739s
user    0m6.193s
sys     0m0.341s
pi@raspberrypi:~/pidi-spotify/pidi_spotify $ time PLAYER_EVENT="volume_set" VOLUME=0 python3 hook.py
oops!

real    0m0.844s
user    0m0.699s
sys     0m0.096s

When raspotify calls /usr/local/bin/pidi_spotify it seems to take even longer - on the order to minutes per event. I'm seeing hundreds of calls to "/usr/local/bin/pidi_spotify --hook" lingering around when just trying to play a few seconds of audio and adjusting the volume.

pi@raspberrypi:~/pidi-spotify/pidi_spotify $ ps aux |grep python3
root      2799  3.2  7.7  68872 37688 ?        Ssl  14:59   1:08 /usr/bin/python3 /usr/local/bin/pidi_spotify
raspoti+  3198 16.0  2.0  17124  9964 ?        R    15:34   0:01 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3199 15.8  2.0  17124  9968 ?        R    15:34   0:01 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3200 10.3  1.7  16104  8752 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3201  9.2  1.5  14928  7808 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3202  8.1  1.5  14672  7360 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3203  8.1  1.4  14572  7312 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3204  7.1  1.4  14316  6988 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3205  6.8  1.4  14316  6860 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3206  7.2  1.3  14316  6704 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3207  6.6  1.3  14060  6788 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3208  6.0  1.3  14060  6760 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3209  5.6  1.3  14060  6548 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3210  6.5  1.2  13804  6300 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3211  5.7  1.2  13804  6280 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
raspoti+  3212  5.5  1.1  13804  5836 ?        R    15:34   0:00 /usr/bin/python3 /usr/local/bin/pidi_spotify --hook
pi        3214  0.0  0.4   7436  2060 pts/0    S+   15:34   0:00 grep --color=auto python3
pi@raspberrypi:~/pidi-spotify/pidi_spotify $
Jestergum commented 2 years ago

I can confirm this, i'm having the same problem. The Rpi completely crashes when giving a few volume changes

What i think is happening is the following : Volume level change Librespot throws an event Hook is called, demanding cpu power Do this a few times (like you would on a phone, mashing the volume key). Hook gets called more times CPU overload ALSA underrun, can't keep up with the music (Acts as a pause .. Start) Librespot throws out more events. Vicious circle and crash.

Can we fix this by exiting the hook if it got called less than 500ms ago or something similar?

Or can anyone give me another idea how to fix this?

Jestergum commented 2 years ago

In my pidi-spotify-hook.log i find a lot of unhandled event: preloading. could it be that this is the reason it doesn't exit the hook function? Would adding an extra classeventhandler be the solution for this?

Jestergum commented 2 years ago

So i added the event, and yes, i'm getting no more unhandled event errors. But the problem still remains : Multiple --hook calls heavily load the cpu (of my tiny rpi zero w) Is it possible due to file opening and checking?

Is there a way to make hook more lean so it ends faster and doesn't consume this much cpu?

Jestergum commented 2 years ago

I have switched to volumio. After a bit of messing around i got it to work there on my Pi zero W

I'm afraid the CPU can't handle the way pidi-spotify handles all the --hook calls.

LunaSquee commented 1 year ago

I rewrote the hook in Bash

#!/bin/bash
FIFO="/tmp/pidi-spotify.fifo"

if [ -z "${PLAYER_EVENT}" ]; then
  exit 1
fi

case "${PLAYER_EVENT}" in
  started | changed | playing | stopped)
    echo "track:${TRACK_ID}:${POSITION_MS:-0}" >> $FIFO
    ;;
  paused)
    echo "pause:${TRACK_ID}" >> $FIFO
    ;;
  volume_set)
    echo "volume:$(( ${VOLUME:-0} * 100 / 65535 ))" >> $FIFO
    ;;
esac

and it suddenly works a lot better. Just save it to a file, chmod +x ./hook.sh and change the raspotify onevent program to the script.