Sep 14 12:41:00 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 14 12:41:02 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 14 12:41:04 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 14 12:41:04 muzyka volumio[1193]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 14 12:41:04 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 14 12:41:04 muzyka volumio[1193]: info: Received Get System Version Sep 14 12:41:04 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 14 12:41:04 muzyka volumio[1193]: info: Received Get System Info Sep 14 12:41:04 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 14 12:41:04 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 14 12:41:04 muzyka volumio[1193]: info: Discovery: Getting this device information Sep 14 12:41:04 muzyka volumio[1193]: info: CoreCommandRouter::volumioGetState Sep 14 12:41:04 muzyka volumio[1193]: info: CorePlayQueue::getTrack 7 Sep 14 12:41:04 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 14 12:41:06 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 14 12:41:06 muzyka systemd[1]: systemd-timedated.service: Deactivated successfully. Sep 14 12:41:08 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 14 12:41:08 muzyka volumio[1193]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 14 12:41:08 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 14 12:41:08 muzyka volumio[1193]: info: Received Get System Version Sep 14 12:41:08 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 14 12:41:08 muzyka volumio[1193]: info: Received Get System Info Sep 14 12:41:08 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 14 12:41:08 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 14 12:41:08 muzyka volumio[1193]: info: Discovery: Getting this device information Sep 14 12:41:08 muzyka volumio[1193]: info: CoreCommandRouter::volumioGetState Sep 14 12:41:08 muzyka volumio[1193]: info: CorePlayQueue::getTrack 7 Sep 14 12:41:08 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 14 12:41:10 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 14 12:41:14 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 14 12:41:18 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 14 12:41:22 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 14 12:41:25 muzyka volumio[1193]: info: CoreCommandRouter::volumioGetState Sep 14 12:41:25 muzyka volumio[1193]: info: CorePlayQueue::getTrack 7 Sep 14 12:41:27 muzyka volumio[1193]: info: Executing endpoint metavolumio Sep 14 12:41:27 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 14 12:41:27 muzyka volumio[1193]: info: Executing endpoint metavolumio Sep 14 12:41:27 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 14 12:41:27 muzyka volumio[1193]: info: Executing endpoint metavolumio Sep 14 12:41:27 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 14 12:41:27 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 14 12:41:27 muzyka volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 14 12:41:27 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 14 12:41:41 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 14 12:41:47 muzyka volumio[1193]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Sep 14 12:41:49 muzyka volumio[1193]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Sep 14 12:41:49 muzyka volumio[1193]: info: Folder /tmp/plugins removed Sep 14 12:41:50 muzyka volumio[1193]: info: Check plugin dependencies Sep 14 12:41:50 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 14 12:41:50 muzyka volumio[1193]: info: Checking if plugin already exists Sep 14 12:41:50 muzyka volumio[1193]: info: Rename folder Sep 14 12:41:50 muzyka volumio[1193]: info: Folder /tmp/downloaded_plugin.zip removed Sep 14 12:41:50 muzyka volumio[1193]: info: Move to category Sep 14 12:41:52 muzyka volumio[1193]: info: Checking if install.sh is present Sep 14 12:41:52 muzyka volumio[1193]: info: Executing install.sh Sep 14 12:41:52 muzyka sudo[2316]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh Sep 14 12:41:52 muzyka sudo[2316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 14 12:41:52 muzyka volumio[1193]: info: Installing Go-librespot Sep 14 12:41:52 muzyka volumio[1193]: info: Checking old vollibrespot installs Sep 14 12:41:52 muzyka systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Sep 14 12:41:52 muzyka dbus-daemon[643]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.33' (uid=0 pid=2324 comm="timedatectl show --property=NTPSynchronized --valu") Sep 14 12:41:52 muzyka systemd[1]: Starting systemd-timedated.service - Time & Date Service... Sep 14 12:41:52 muzyka systemd[1]: Reloading. Sep 14 12:41:52 muzyka dbus-daemon[643]: [system] Successfully activated service 'org.freedesktop.timedate1' Sep 14 12:41:52 muzyka setdatetime-helper.sh[2323]: Time is not synchronized. Attempting to sync... Sep 14 12:41:53 muzyka sudo[2346]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Sun, 14 Sep 2025 10:41:54 GMT#015' Sep 14 12:41:53 muzyka sudo[2346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Sep 14 12:41:54 muzyka setdatetime-helper.sh[2351]: Sun Sep 14 12:41:54 CEST 2025 Sep 14 12:41:54 muzyka sudo[2346]: pam_unix(sudo:session): session closed for user root Sep 14 12:41:54 muzyka setdatetime-helper.sh[2323]: Time synchronized successfully. Sep 14 12:41:54 muzyka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 14 12:41:54 muzyka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 14 12:41:54 muzyka systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Sep 14 12:41:54 muzyka systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Sep 14 12:41:54 muzyka systemd[1]: Started systemd-timedated.service - Time & Date Service. Sep 14 12:41:54 muzyka volumio[1193]: info: Downloading daemon Sep 14 12:41:57 muzyka volumio[1193]: info: Creating directories Sep 14 12:41:57 muzyka volumio[1193]: info: Creating data directory Sep 14 12:41:59 muzyka volumio[1193]: info: Creating Start Script Sep 14 12:41:59 muzyka systemd[1]: Reloading. Sep 14 12:42:00 muzyka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 14 12:42:00 muzyka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 14 12:42:00 muzyka sudo[2316]: pam_unix(sudo:session): session closed for user root Sep 14 12:42:00 muzyka volumio[1193]: info: Install script completed Sep 14 12:42:00 muzyka volumio[1193]: info: Adding reference to registry Sep 14 12:42:00 muzyka volumio[1193]: info: Done installing plugin. Sep 14 12:42:00 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 14 12:42:00 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 14 12:42:00 muzyka volumio[1193]: info: Folder /tmp/plugins removed Sep 14 12:42:00 muzyka volumio[1193]: info: Folder /tmp/downloaded_plugin.zip removed Sep 14 12:42:00 muzyka volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 14 12:42:00 muzyka volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 14 12:42:00 muzyka volumio[1193]: Plugin install end detected on script Sep 14 12:42:00 muzyka volumio[1193]: info: Folder /data/temp removed Sep 14 12:42:01 muzyka volumio[1193]: info: Enabling plugin spop Sep 14 12:42:01 muzyka volumio[1193]: info: Loading plugin "spop"... Sep 14 12:42:03 muzyka volumio[1193]: info: PLUGIN START: spop Sep 14 12:42:03 muzyka volumio[1193]: info: Creating Spotify config file Sep 14 12:42:03 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 14 12:42:03 muzyka volumio[1193]: info: Done. Sep 14 12:42:03 muzyka volumio[1193]: info: Spotify config file written Sep 14 12:42:03 muzyka volumio[1193]: info: No need to fix Spotify hosts Sep 14 12:42:03 muzyka sudo[2399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 14 12:42:03 muzyka sudo[2399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 14 12:42:03 muzyka systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 14 12:42:03 muzyka systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 14 12:42:03 muzyka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 14 12:42:03 muzyka go-librespot[2401]: go-librespot daemon starting... Sep 14 12:42:03 muzyka sudo[2399]: pam_unix(sudo:session): session closed for user root Sep 14 12:42:03 muzyka go-librespot[2402]: time="2025-09-14T12:42:03+02:00" level=info msg="running go-librespot 0.3.2" Sep 14 12:42:03 muzyka go-librespot[2402]: time="2025-09-14T12:42:03+02:00" level=debug msg="no app state found" Sep 14 12:42:03 muzyka go-librespot[2402]: time="2025-09-14T12:42:03+02:00" level=debug msg="stored credentials not found" Sep 14 12:42:03 muzyka go-librespot[2402]: time="2025-09-14T12:42:03+02:00" level=info msg="generated new device id: b542fb97aeefd6872f8fff41fa57ccc02521d581" Sep 14 12:42:03 muzyka go-librespot[2402]: time="2025-09-14T12:42:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 14 12:42:03 muzyka go-librespot[2402]: time="2025-09-14T12:42:03+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 14 12:42:03 muzyka go-librespot[2402]: time="2025-09-14T12:42:03+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 14 12:42:03 muzyka go-librespot[2402]: time="2025-09-14T12:42:03+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 14 12:42:03 muzyka go-librespot[2402]: time="2025-09-14T12:42:03+02:00" level=info msg="zeroconf server listening on port 37191" Sep 14 12:42:03 muzyka go-librespot[2402]: time="2025-09-14T12:42:03+02:00" level=debug msg="obtained new client token: AABJZkJHgwZo2jjHaENuyOOXhlYksSzxIq6ZFZSZyXZpjjXdmiJXIrCoSSobhbT8MzL7WCv1gOE+EkxNcH7jHX5ZsukZsTAtVEmEIBvRCIkvfnUxeqihEYA1U4uxVF6iSeuQm5HmttfXNojUla9g87etMXoDht686kJvyixEztxzy/fQk6+ZBmLKr30UOtdlaSxyOaJKdOYbWPdcZGA/UROsU1ND2Nb3zYYhKPByKIC9uDj4nQOO" Sep 14 12:42:03 muzyka volumio[1193]: info: An error occurred while refreshing Spotify Token Error: Bad Request Sep 14 12:42:04 muzyka go-librespot[2402]: time="2025-09-14T12:42:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 14 12:42:04 muzyka go-librespot[2402]: time="2025-09-14T12:42:04+02:00" level=debug msg="completed keyexchange" Sep 14 12:42:04 muzyka go-librespot[2402]: time="2025-09-14T12:42:04+02:00" level=debug msg="completed challenge" Sep 14 12:42:04 muzyka volumio[1193]: info: CoreCommandRouter::volumioGetState Sep 14 12:42:04 muzyka volumio[1193]: info: CorePlayQueue::getTrack 7 Sep 14 12:42:04 muzyka go-librespot[2402]: time="2025-09-14T12:42:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 14 12:42:04 muzyka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 14 12:42:04 muzyka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 14 12:42:05 muzyka volumio[1193]: info: Retrieving Cloud Streaming UI Sep 14 12:42:05 muzyka volumio[1193]: info: Getting Tidal Cloud Configuration Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 14 12:42:05 muzyka volumio[1193]: info: Getting Qobuz Cloud Configuration Sep 14 12:42:05 muzyka volumio[1193]: info: Asking plugin for UI Config Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 14 12:42:05 muzyka volumio[1193]: info: Getting Spotify Cloud Configuration Sep 14 12:42:05 muzyka volumio[1193]: info: Asking plugin for UI Config Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 14 12:42:05 muzyka volumio[1193]: info: Saving Spotify Acccount Sep 14 12:42:05 muzyka volumio[1193]: info: Got it Sep 14 12:42:05 muzyka volumio[1193]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 14 12:42:05 muzyka volumio[1193]: info: Got Tidal Cloud Configuration Sep 14 12:42:05 muzyka volumio[1193]: info: Got it Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::volumioGetBrowseSources Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::volumioGetBrowseSources Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::volumioGetBrowseSources Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 14 12:42:05 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Sep 14 12:42:06 muzyka volumio[1193]: info: Executing endpoint metavolumio Sep 14 12:42:06 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 14 12:42:06 muzyka volumio[1193]: info: Executing endpoint metavolumio Sep 14 12:42:06 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 14 12:42:06 muzyka volumio[1193]: info: Executing endpoint metavolumio Sep 14 12:42:06 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 14 12:42:06 muzyka volumio[1193]: info: go-librespot daemon successfully initialized Sep 14 12:42:07 muzyka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 14 12:42:07 muzyka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 14 12:42:07 muzyka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 14 12:42:07 muzyka go-librespot[2410]: go-librespot daemon starting... Sep 14 12:42:07 muzyka go-librespot[2411]: time="2025-09-14T12:42:07+02:00" level=info msg="running go-librespot 0.3.2" Sep 14 12:42:07 muzyka go-librespot[2411]: time="2025-09-14T12:42:07+02:00" level=debug msg="app state loaded" Sep 14 12:42:07 muzyka go-librespot[2411]: time="2025-09-14T12:42:07+02:00" level=debug msg="stored credentials not found" Sep 14 12:42:07 muzyka go-librespot[2411]: time="2025-09-14T12:42:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 14 12:42:07 muzyka go-librespot[2411]: time="2025-09-14T12:42:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 14 12:42:07 muzyka go-librespot[2411]: time="2025-09-14T12:42:07+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 14 12:42:07 muzyka go-librespot[2411]: time="2025-09-14T12:42:07+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 14 12:42:07 muzyka go-librespot[2411]: time="2025-09-14T12:42:07+02:00" level=info msg="zeroconf server listening on port 45941" Sep 14 12:42:08 muzyka go-librespot[2411]: time="2025-09-14T12:42:08+02:00" level=debug msg="obtained new client token: AACL69htlyJyS/qeQ7U/yEedF9ZOLD8FKwY/iPK2v1Bsq6tl3gocf1WtAqJdU9eVhE6J41XSZDorpiaQCuq+eO0NtBWAPxp3oU+gKPX6glcUlXH4cklycjx496K/vUsRVBqy32P7GAC6dKYAxiht8RwE1/Zin0R7+PY8fErRPaZFi1G00cwGfpCm2LHYLJybFxb5o848GFBb5VOgoIeZqdjsOmnmtXVRC58cSLeWCYVj07pRpQk+" Sep 14 12:42:08 muzyka go-librespot[2411]: time="2025-09-14T12:42:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 14 12:42:08 muzyka go-librespot[2411]: time="2025-09-14T12:42:08+02:00" level=debug msg="completed keyexchange" Sep 14 12:42:08 muzyka go-librespot[2411]: time="2025-09-14T12:42:08+02:00" level=debug msg="completed challenge" Sep 14 12:42:08 muzyka go-librespot[2411]: time="2025-09-14T12:42:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 14 12:42:08 muzyka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 14 12:42:08 muzyka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 14 12:42:09 muzyka volumio[1193]: info: Initializing connection to go-librespot Websocket Sep 14 12:42:09 muzyka volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 14 12:42:09 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 14 12:42:11 muzyka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 14 12:42:11 muzyka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 14 12:42:11 muzyka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 14 12:42:11 muzyka go-librespot[2419]: go-librespot daemon starting... Sep 14 12:42:11 muzyka go-librespot[2420]: time="2025-09-14T12:42:11+02:00" level=info msg="running go-librespot 0.3.2" Sep 14 12:42:11 muzyka go-librespot[2420]: time="2025-09-14T12:42:11+02:00" level=debug msg="app state loaded" Sep 14 12:42:11 muzyka go-librespot[2420]: time="2025-09-14T12:42:11+02:00" level=debug msg="stored credentials not found" Sep 14 12:42:11 muzyka go-librespot[2420]: time="2025-09-14T12:42:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 14 12:42:11 muzyka go-librespot[2420]: time="2025-09-14T12:42:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 14 12:42:11 muzyka go-librespot[2420]: time="2025-09-14T12:42:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 14 12:42:11 muzyka go-librespot[2420]: time="2025-09-14T12:42:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 14 12:42:11 muzyka go-librespot[2420]: time="2025-09-14T12:42:11+02:00" level=info msg="zeroconf server listening on port 39855" Sep 14 12:42:11 muzyka go-librespot[2420]: time="2025-09-14T12:42:11+02:00" level=debug msg="obtained new client token: AABIxndvuYBcTwuUrzx3SgFyEBHaG7VbKwd40Vq+7PyQqZRws0Brn6b5Vf2n0cJwoPFJEyZUF2EJW29c5YrqIexi8rT1VM4GkiqTZwQlWYfhyIOrriuJyLx5JeNns/nwE6AqoAVTlim7lXvWplX70EG1dSRfJpN9zDsyuGfYjW5RHwbCzR8uV/050HsYwbmDkbo5eakqh8ivYBs47S/R5n92q6i9Lg3hUrAStfm5+V+Jnid/vqMF" Sep 14 12:42:12 muzyka go-librespot[2420]: time="2025-09-14T12:42:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 14 12:42:12 muzyka volumio[1193]: info: Initializing connection to go-librespot Websocket Sep 14 12:42:12 muzyka go-librespot[2420]: time="2025-09-14T12:42:12+02:00" level=debug msg="new websocket client" Sep 14 12:42:12 muzyka volumio[1193]: info: Connection to go-librespot Websocket established Sep 14 12:42:12 muzyka go-librespot[2420]: time="2025-09-14T12:42:12+02:00" level=debug msg="completed keyexchange" Sep 14 12:42:12 muzyka go-librespot[2420]: time="2025-09-14T12:42:12+02:00" level=debug msg="completed challenge" Sep 14 12:42:12 muzyka go-librespot[2420]: time="2025-09-14T12:42:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 14 12:42:12 muzyka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 14 12:42:12 muzyka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 14 12:42:12 muzyka volumio[1193]: info: Connection to go-librespot Websocket closed Sep 14 12:42:13 muzyka volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 14 12:42:15 muzyka volumio[1193]: info: Getting Spotify volume Sep 14 12:42:15 muzyka volumio[1193]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 14 12:42:15 muzyka volumio[1193]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 14 12:42:15 muzyka volumio[1193]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 14 12:42:15 muzyka volumio[1193]: errno: -111, Sep 14 12:42:15 muzyka volumio[1193]: code: 'ECONNREFUSED', Sep 14 12:42:15 muzyka volumio[1193]: syscall: 'connect', Sep 14 12:42:15 muzyka volumio[1193]: address: '127.0.0.1', Sep 14 12:42:15 muzyka volumio[1193]: port: 9879, Sep 14 12:42:15 muzyka volumio[1193]: response: undefined Sep 14 12:42:15 muzyka volumio[1193]: } Sep 14 12:42:15 muzyka volumio[1193]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 14 12:42:15 muzyka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 14 12:42:15 muzyka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 14 12:42:15 muzyka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 14 12:42:15 muzyka go-librespot[2452]: go-librespot daemon starting... Sep 14 12:42:15 muzyka go-librespot[2454]: time="2025-09-14T12:42:15+02:00" level=info msg="running go-librespot 0.3.2" Sep 14 12:42:15 muzyka go-librespot[2454]: time="2025-09-14T12:42:15+02:00" level=debug msg="app state loaded" Sep 14 12:42:15 muzyka go-librespot[2454]: time="2025-09-14T12:42:15+02:00" level=debug msg="stored credentials not found" Sep 14 12:42:15 muzyka go-librespot[2454]: time="2025-09-14T12:42:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 14 12:42:16 muzyka go-librespot[2454]: time="2025-09-14T12:42:16+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 14 12:42:16 muzyka go-librespot[2454]: time="2025-09-14T12:42:16+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 14 12:42:16 muzyka go-librespot[2454]: time="2025-09-14T12:42:16+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 14 12:42:16 muzyka go-librespot[2454]: time="2025-09-14T12:42:16+02:00" level=info msg="zeroconf server listening on port 46329" Sep 14 12:42:16 muzyka go-librespot[2454]: time="2025-09-14T12:42:16+02:00" level=debug msg="obtained new client token: AABGA5ZwvLaFGjpnEVtWp2ww9h8nFxLjmnO+6WC26YmMRuB4wFDDioSFPIyTYBUHQcIBeYn6SX2SK2xsPVaSFJMPC7CNSMB3M0+Q7JQSlvmEBooVjOFVtVGz+ogtVdMHcQ9BUWNFQQ+m5ACWk/C67Eu057I1HYII27opuP23go9Iau89WNp0WoaaijyoJhZiUzcp4ak7x9rMCnVRAJy85VqMFWX0YnUqbD3t7nB9GtfbjC10Ru/+mmQ=" Sep 14 12:42:16 muzyka go-librespot[2454]: time="2025-09-14T12:42:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 14 12:42:16 muzyka go-librespot[2454]: time="2025-09-14T12:42:16+02:00" level=debug msg="completed keyexchange" Sep 14 12:42:16 muzyka go-librespot[2454]: time="2025-09-14T12:42:16+02:00" level=debug msg="completed challenge" Sep 14 12:42:16 muzyka go-librespot[2454]: time="2025-09-14T12:42:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Sep 14 12:42:16 muzyka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 14 12:42:16 muzyka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 14 12:42:17 muzyka sudo[2465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-09-14 12:41' Sep 14 12:42:17 muzyka sudo[2465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="4a70cb031e64a8e498efc3e29470650871ff7d54" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat May 31 04:09:10 UTC 2025" VOLUMIO_VERSION="4.005" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="f9bd4447a30d4b2c74b3880e7a50e48b"