Spotify Connect failures on Moode 4.4

[abyrd]

Hello, thanks for all your work on this project.

I am running Moode 4.4 on a Pi 3 B+ with HiFiBerry DAC+. The network connection is wifi but the following problem has been observed on a wired connection.

I can use Moode as a Spotify Connect device for a while, but then it disappears from the devices list on the Spotify app. I know many other people have reported similar problems and I have read through the forum posts. However, many posts say that the problem is due to an audio cache filling up the disk, and that this will be fixed in 4.4. My problem is still occurring on 4.4, and df reports many GB of free space. I have Spotify Premium and have enabled Spotify in the Moode web UI settings.

I am using the MacOS Spotify app. Moode appears in the devices list (which shows a blue dot indicating the presence of Spotify Connect devices), I can select Moode and listen to music. But at some point the sound stops, and Moode has disappeared from that devices list. At this point running pgrep on the Pi shows no librespot process running. I can use the Moode web UI to restart the Spotify service, at which point Moode immediately reappears in the Spotify MacOS app. If I select Moode as the connect device in the Spotify app, Moode again disappears from that app, and again running pgrep on the Pi shows no librespot process running.

I eventually tried changing the name of the Spotify Connect service via the Moode web UI, and bizarrely as soon as I changed the name, when I restarted Spotify via the Moode web UI, Spotify Connect was then useable for quite a while. But eventually the same problem returned - trying to use the Moode Spotify Connect device would cause the process to crash silently.

I have grepped /var/log and can barely find any references to librespot in the logs. In auth.log I see the commands where sudo is used to killall librespot and restart librespot with all my chosen settings.

auth.logec 13 22:45:03 moode sudo:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall librespot
auth.logec 13 22:45:03 moode sudo:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/local/bin/librespot --name moode --bitrate 320 --initial-volume 0 --linear-volume --cache /var/local/www/spotify_cache --disable-audio-cache --backend alsa --device plughw:0 --onevent /var/local/www/commandw/spotevent.sh

Here's where it gets really interesting. If I SSH into the Pi and run those exact same librespot commands manually on the command line, I can see the console output from librespot interacting with the Spotify MacOS app and _it doesn't crash_. I can listen to music for hours with no problem. This works both with the command shown in auth.log as well as a simplified command where I specify only --name and --linear-volume and don't run under sudo (run as the pi user).

After successfully using librespot on the command line, I restarted the Spotify service via the web UI it continued to work well for quite a while, even after a reboot of the Pi.

I have no idea which of the above actions, if any, actually caused librespot to work or fail. But behavior was noticeably different at different times, varying from complete stability to instant crash. Of course this could have been due to other external factors but renaming the Connect device and running on the command line seemed to have an immediate effect.

Here is some output from sysinfo.sh:

A U D I O    P A R A M E T E R S  

Audio device = HiFiBerry DAC+
Interface = I2S
Hdwr volume = Controller detected
Mixer name = Digital
Output stream = S16_LE / 44100
ALSA version = 1.1.3-5+rpi3
SoX version = 0.1.2-2


S P O T I F Y    S E T T I N G S  

Friendly name = moode
ALSA device = default:CARD=sndrpihifiberry
Resume MPD = No
Bit rate = 320
Initial volume = 0
Volume curve = Linear
Volume normalization = No
Normalization pregain = 0

I hope this information might help understand the problem, let me know if you need any other information.

[Tim Curtis]

Hi,

Thanks for the detailed report :-)

It seems that librespot, while very good is still not rock stable and so we must wait for the dev's to work through the bugs.

[abyrd]

Hi,

Thanks for the detailed report :-)

It seems that librespot, while very good is still not rock stable and so we must wait for the dev's to work through the bugs.

Yes, I thought it might just be down to librespot stability, but I wanted to share my observations in case it helps other Moode users, and to track improvement or changes. I understand we may just need to wait for fixes to the dependency, but I thought it might be significant that librespot seems to work flawlessly on the command line.

I'm wondering what could be different in normal operation. Is there any chance that background librespot is hitting permissions problems, perhaps when calling the event handler script? I guess not since it's always running as root.

[abyrd]

I'm also wondering if there's some way I can observe the librespot failure and get a stack trace or core dump to share with the developers. I'm surprised it just dies with no log messages. Is there a way in Moode to retain the stdout / stderr of these background processes? Maybe I should go ask the librespot team but I thought I should first eliminate the possibility that it's something about the Moode environment in which librespot is being run.

[Tim Curtis]

Hi,

The code below should get you the runtime output from librespot :-)

You need to edit function startSpotify() in file /var/www/inc/playerlib.php, then reboot.

Comment out this line
//' > /dev/null 2>&1 &';

Add this line below it
' -v > /home/pi/librespot.txt 2>&1 &'; 

PHP Code:

$cmd = 'librespot' . 
' --name "' . $_SESSION['spotifyname'] . '"' .
' --bitrate ' . $cfg_spotify['bitrate'] . 
' --initial-volume ' . $cfg_spotify['initial_volume'] . 
$linear_volume . 
$volume_normalization .
' --cache /var/local/www/spotify_cache --disable-audio-cache --backend alsa --device "' . $device . '"' . // r44d audio file cache eats disk space
' --onevent /var/local/www/commandw/spotevent.sh' . 
//' > /dev/null 2>&1 &';
' -v > /home/pi/librespot.txt 2>&1 &'; 


-Tim

[moode_user]

I can use the Moode web UI to restart the Spotify service, at which point Moode immediately reappears in the Spotify MacOS app. If I select Moode as the connect device in the Spotify app, Moode again disappears from that app, and again running pgrep on the Pi shows no librespot process running.

I observed the same behavior on a Raspberry Pi Zero W with MoodeAudio 4.3 and 4.4, not only with the MacOS app. Spotify Connect was unusable.

What helped was to log in via SSH and once start librespot with a (premium) Spotify user name and password:

Code:

librespot -n "client_name" -u user -p password

After that it worked flawlessly, even after restarting Spotify Connect from the MoodeAudio web interface.

I would thus argue that MoodeAudio is doing something wrong here.

On a sidenote, it would be nice if any kind of latest connection to MoodeAudio had priority over previous ones, e.g., if Spotify Connect did not remain silent due to a previously established Bluetooth connection.

[Tim Curtis]

Hi,

librespot picks up the credentials from the Spotify app when it connects and thus no need to manually enter userid and pwd in the librespot launch string.

Try the procedure in post #5 and then post back the debug output after you experience a failure.

There is a TODO item to investigate disconnecting Bluetooth when either Spotify, Airplay or Squeezelite renderer is activated.

[moode_user]

librespot picks up the credentials from the Spotify app when it connects and thus no need to manually enter userid and pwd in the librespot launch string.

In theory, that is what should happen and what I would have expected. In practice, the librespot issues stopped after starting librespot with  credentials once. Initiating librespot from the console without credentials, which I had also tried, did not fix the crashes. Neither did restarting librespot from the MoodeAudio web interface.

This may be coincidence, of course. Since it is very easy to try, though, I encourage people to test and possibly falsify this.

[TheOldPresbyope]

There are 59 open issues in the librespot github repo. A number of them have the word "crash" in their title. The reported symptoms vary, since usage varies, as do the guesses of the causes. Frequently a momentary interruption of Internet service is hypothesized. I found this comment from a maintainer in response to a recent issue

My gut feeling is that this is a combination of Connect being buggy, and also is not handling reconnections. I suspect if/when we get around to implementing reconnection logic, the frequency of this bug should significantly decrease, and any remaining occurrences will likely be chalked up to server side errors

According to the current build_recipe_v2.7.txt, librespot is being built from the sources at commit a4e0f58 which dates back to August. While it isn't clear from the github log just what issues the subsequent commits are likely to resolve, you could try building from the current sources on the master branch and see if you get a more-stable result.

I'm able to listen to Spotify for hours here---Spotify app on a iPad, moOde r4.4 on an RPi3B+ connected via WiFi, decent ISP connectivity via Verizon FiOS. Maybe I've just been lucky but I haven't run into the issue reported here.

Regards,
Kent

[moode_user]

There are 59 open issues in the librespot github repo. A number of them have the word "crash" in their title. 

What I suggested is certainly not the solution to all of those.

Frequently a momentary interruption of Internet service is hypothesized.

This I can rule out in my setting.

you could try building from the current sources on the master branch and see if you get a more-stable result.

Starting librespot one time with the user credentials fixed the issues for me and gave me a very stable result, not only once but on two Raspberry Pi Zero Ws (first with MoodeAudio 4.3, then with 4.4), which is why I shared this observation here.

There may be something wrong with how librespot receives and handles the credentials sent by an app. A one-time manual input might possibly "fix" something there. This is pure speculation but very easy to try out. Hence I suggest that people who are experiencing the exact issues described in this thread give the suggested solution a quick try and report back. If more people find this to be working, it may help with figuring out a bug.

Instead, we can, of course, also decide to further discuss (with rather limited knowledge about the workings of librespot) why this should theoretically not be necessary or help.

I'm able to listen to Spotify for hours here

Me too, after having done what I described.