in the amplipi ui add a spotify-stream connected to some zone
in the spotify UI select the devices to connect
– it shows the amplipi-stream alright
– after selecting that, the spotify UI keeps trying to connect to it, but never succeeds
– trying to reconnect, the amplipi stream is no longer in the list
To troubleshoot this I performed these actions:
another upgrade, now to 0.3.5 of amplipi
a drop and re-create of my spotify-streams on the amplipi
replay of the scenario while having a ssh open to the amplipi listing the output of journalctl -f
that last action gives me these outputs:
1| at the time of opening the stream I named “K79E”:
May 04 03:53:35 amplipi authbind[835]: Starting process monitor for process: ['alsaloop', '-C', 'lb1p', '-P', 'ch0', '-t', '100000']
May 04 03:53:35 amplipi authbind[835]: Forwarding signal 15 to subprocess.
May 04 03:53:35 amplipi authbind[835]: Loading config from "./config.toml"
May 04 03:53:35 amplipi authbind[835]: No username specified. Checking username_cmd
May 04 03:53:35 amplipi authbind[835]: No username_cmd specified
May 04 03:53:35 amplipi authbind[835]: No password specified. Checking password_cmd
May 04 03:53:35 amplipi authbind[835]: No password_cmd specified
May 04 03:53:35 amplipi authbind[835]: No proxy specified
May 04 03:53:35 amplipi authbind[835]: Using software volume controller.
May 04 03:53:35 amplipi authbind[835]: no usable credentials found, enabling discovery
May 04 03:53:35 amplipi authbind[835]: Activating K79E (persistant)
May 04 03:53:35 amplipi authbind[835]: starting connection via: /home/pi/amplipi-dev/venv/bin/python /home/pi/amplipi-dev/streams/process_monitor.py alsaloop -C lb2p -P ch0 -t 100000
2| at the time of connecting to that in the spotify UI:
May 04 03:53:49 amplipi authbind[835]: Connecting to AP "ap.spotify.com:443"
May 04 03:53:49 amplipi authbind[835]: Authenticated as "cvm55e8y1wmyc6jos5k1t9eq1" !
May 04 03:53:49 amplipi authbind[835]: Country: "BE"
May 04 03:53:49 amplipi authbind[835]: Using Alsa sink with format: S16
May 04 03:53:49 amplipi authbind[835]: error 403 for uri hm://keymaster/token/authenticated?client_id=2c1ea588dfbc4a989e2426f8385297c3&scope=user-read-playback-state,user-modify-playback-state,user-read-currently-playing
May 04 03:53:49 amplipi authbind[835]: failed to request a token for the web API
I will do some google searching on that failure, but already welcome any advice / tips you might have.
I’m not sure if this always happens or it is an intermittent issue.
For the ladder case I would suggest trying to reset the Spotify stream after this happens. I added some instructions for resetting the LMS stream here: LMS client not appearing on LMS server - #3 by linknum23 , Spotify will work the same way.
Either way we’ll try to investigate this and see if we can reproduce it.
it keeps on happening for some weeks now, so ‘intermittent’ starts feeling as the kind of hope we should abandon?
also trying your suggested curl commands yields a “method not allowed” both at client and server (ssh log)
clientside:
$ curl -X POST --url "http://amplipi.marcels.lan/streams/1010/deactivate"
{"detail":"Method Not Allowed"}
$ curl -X POST --url "http://amplipi.marcels.lan/streams/1010/activate"
{"detail":"Method Not Allowed"}
serverside: (ssh with running journatctl -f)
May 05 14:26:17 amplipi authbind[835]: INFO: 10.0.100.136:34628 - "POST /streams/1010/deactivate HTTP/1.1" 405 Method Not Allowed
May 05 14:29:45 amplipi authbind[835]: INFO: 10.0.100.136:51412 - "POST /streams/1010/activate HTTP/1.1" 405 Method Not Allowed
possibly unrelated I am also seeing these messages fly by in the server side logging:
May 05 14:26:40 amplipi authbind[835]: Dbus error getting MPRIS metadata: The name org.mpris.MediaPlayer2.spotifyd.instance1592 was not provided by any .service files
not on a fixed interval but roughly every 5 to 30 seconds
and always in bursts of four
which made me think that it might not be a coincidence that I have 4 spotify streams defined…
so I ended up throwing away my spotify streams once more: and those MPRIS metadata logs are no longer appearing
no avail – after (1) reboot (2) added new spotify stream (3) using it in a zone (4) trying to connect with the clientonly to (5) get the 403 error message in the logs:
May 05 14:47:14 amplipi authbind[830]: Connecting to AP "ap.spotify.com:443"
May 05 14:47:14 amplipi authbind[830]: Authenticated as "cvm55e8y1wmyc6jos5k1t9eq1" !
May 05 14:47:14 amplipi authbind[830]: Country: "BE"
May 05 14:47:14 amplipi authbind[830]: Using Alsa sink with format: S16
May 05 14:47:14 amplipi authbind[830]: error 403 for uri hm://keymaster/token/authenticated?client_id=2c1ea588dfbc4a989e2426f8385297c3&scope=user-read-playback-state,user-modify-playback-state,user-read-currently-playing
as well as the bursts of 4 MPRIS metadata messages
funny that now I only have one spotify stream defined, those messages still come in bursts of 4, so that might have been a coincidence there…
have to say I am at loss here, happy to be executing more testing commands…
I talked to Jason this morning and he is having similar issues at his house as well.
We just compiled the latest version of spotifyd and are testing it out at the office.
Of course you were right – no more errors about unsupported POST method when I slide in the /api/ part
However this “re-activate trick” only helps to re-show the stream in the list of available options in the sportify client after the failure to connect. So it avoids me the trouble of dropping and recreating the stream. But the actual reconnect still fails.
Looks like your work on the spotifyd is the currently remaining road to a solution. Any news on that?
I started playing with the latest unreleased version of spotifyd. Initial results were promising. It connected reliably to Spotify and appeared to integrate some new features. However it was notably a little unstable, after 4 hours it stopped and threw an error.
Internally we are running a new version of Spotifyd (combined with a fair amount of AmpliPi updates) that appears to fix all of the stability problems we were seeing. Stay tuned, we’re hoping it makes it into the next release.