Aug 31 08:35:01 prmspoti01 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 31 08:35:02 prmspoti01 systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 31 08:35:02 prmspoti01 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 31 08:35:04 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioGetQueue Aug 31 08:35:04 prmspoti01 volumio[1603]: info: CoreStateMachine::getQueue Aug 31 08:35:04 prmspoti01 volumio[1603]: info: CorePlayQueue::getQueue Aug 31 08:35:05 prmspoti01 volumio[1603]: info: Preload queue cleared Aug 31 08:35:05 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 08:35:05 prmspoti01 volumio[1603]: info: CoreStateMachine::ClearQueue Aug 31 08:35:05 prmspoti01 volumio[1603]: info: CoreStateMachine::stop Aug 31 08:35:05 prmspoti01 volumio[1603]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 08:35:05 prmspoti01 volumio[1603]: info: CorePlayQueue::clearPlayQueue Aug 31 08:35:05 prmspoti01 volumio[1603]: info: CorePlayQueue::saveQueue Aug 31 08:35:05 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioPushQueue Aug 31 08:35:05 prmspoti01 volumio[1603]: info: CoreStateMachine::addQueueItems Aug 31 08:35:05 prmspoti01 volumio[1603]: info: CorePlayQueue::addQueueItems Aug 31 08:35:05 prmspoti01 volumio[1603]: info: Preload queue cleared Aug 31 08:35:05 prmspoti01 volumio[1603]: info: Adding Item to queue: spotify:playlist:37i9dQZF1DWX7rdRjOECPW Aug 31 08:35:05 prmspoti01 volumio[1603]: info: Exploding uri spotify:playlist:37i9dQZF1DWX7rdRjOECPW in service spop Aug 31 08:35:05 prmspoti01 volumio[1603]: SPOTIFY: EXPLODING URI:spotify:playlist:37i9dQZF1DWX7rdRjOECPW Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioPushQueue Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CorePlayQueue::saveQueue Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CoreStateMachine::updateTrackBlock Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrackBlock Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioPlay Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CoreStateMachine::play index 0 Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CoreStateMachine::stop Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CoreStateMachine::play index undefined Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrack 0 Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CoreStateMachine::startPlaybackTimer Aug 31 08:35:06 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrack 0 Aug 31 08:35:06 prmspoti01 volumio[1603]: info: [1788158106574] ControllerSpotify::clearAddPlayTrack Aug 31 08:35:06 prmspoti01 volumio[1603]: info: Sending Spotify command with payload to local API: /player/play Aug 31 08:35:09 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioGetState Aug 31 08:35:09 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrack 0 Aug 31 08:35:15 prmspoti01 volumio[1603]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Aug 31 08:35:43 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 08:35:43 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 31 08:35:45 prmspoti01 volumio[1603]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 08:35:48 prmspoti01 volumio[1603]: info: Received OAUTH Data Aug 31 08:35:48 prmspoti01 volumio[1603]: info: Executing Spotify Oauth Login Aug 31 08:35:48 prmspoti01 volumio[1603]: info: Saving Spotify Refresh Token Aug 31 08:35:48 prmspoti01 volumio[1603]: info: New Spotify access tokenBQDNx_qJPr... Aug 31 08:35:48 prmspoti01 volumio[1603]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 31 08:35:48 prmspoti01 sudo[2386]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 08:35:48 prmspoti01 sudo[2386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 08:35:48 prmspoti01 sudo[2388]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 08:35:48 prmspoti01 sudo[2388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 08:35:48 prmspoti01 sudo[2386]: pam_unix(sudo:session): session closed for user root Aug 31 08:35:48 prmspoti01 sudo[2388]: pam_unix(sudo:session): session closed for user root Aug 31 08:35:49 prmspoti01 volumio[1603]: verbose: New Socket.io Connection to 10.10.27.100 from 10.10.16.93 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Aug 31 08:35:49 prmspoti01 volumio[1603]: SPOTIFY: User informations: {"account_id":"eEVcuAYxbi","country":"DE","display_name":"RBHF","email":"neele@heidls.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31zkorqwbihqq4fmlvhb6eiyufp4"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/31zkorqwbihqq4fmlvhb6eiyufp4","id":"31zkorqwbihqq4fmlvhb6eiyufp4","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85d21fd6c4cfe3111ab0fb264b","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82d21fd6c4cfe3111ab0fb264b","width":64}],"product":"premium","type":"user","uri":"spotify:user:31zkorqwbihqq4fmlvhb6eiyufp4"} Aug 31 08:35:49 prmspoti01 volumio[1603]: info: Creating Spotify config file Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 08:35:49 prmspoti01 volumio[1603]: info: Spotify config file written Aug 31 08:35:49 prmspoti01 sudo[2392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 08:35:49 prmspoti01 sudo[2392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 08:35:49 prmspoti01 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 31 08:35:49 prmspoti01 volumio[1603]: info: Connection to go-librespot Websocket closed Aug 31 08:35:49 prmspoti01 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 31 08:35:49 prmspoti01 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:35:49 prmspoti01 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:35:49 prmspoti01 go-librespot[2394]: go-librespot daemon starting... Aug 31 08:35:49 prmspoti01 sudo[2392]: pam_unix(sudo:session): session closed for user root Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=debug msg="app state loaded" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=debug msg="stored credentials not found" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 08:35:49 prmspoti01 volumio[1603]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Aug 31 08:35:49 prmspoti01 volumio[1603]: info: New Spotify access tokenBQCZLLpPYd... Aug 31 08:35:49 prmspoti01 volumio[1603]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+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]" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+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]" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+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]" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=info msg="zeroconf server listening on port 34675" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioGetState Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrack 0 Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 31 08:35:49 prmspoti01 volumio[1603]: info: Received Get System Info Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 08:35:49 prmspoti01 volumio[1603]: info: Discovery: Getting this device information Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioGetState Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrack 0 Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioGetState Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrack 0 Aug 31 08:35:49 prmspoti01 volumio[1603]: info: Listing playlists Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 31 08:35:49 prmspoti01 volumio[1603]: SPOTIFY: User informations: {"account_id":"eEVcuAYxbi","country":"DE","display_name":"RBHF","email":"neele@heidls.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31zkorqwbihqq4fmlvhb6eiyufp4"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/31zkorqwbihqq4fmlvhb6eiyufp4","id":"31zkorqwbihqq4fmlvhb6eiyufp4","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85d21fd6c4cfe3111ab0fb264b","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82d21fd6c4cfe3111ab0fb264b","width":64}],"product":"premium","type":"user","uri":"spotify:user:31zkorqwbihqq4fmlvhb6eiyufp4"} Aug 31 08:35:49 prmspoti01 volumio[1603]: info: Spotify Successfully logged in Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 08:35:49 prmspoti01 volumio[1603]: info: [1788158149254] CoreMusicLibrary::Adding element Spotify Aug 31 08:35:49 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 08:35:49 prmspoti01 volumio[1603]: Cannot find translation for source YouTube2 Aug 31 08:35:49 prmspoti01 volumio[1603]: Cannot find translation for source Spotify Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=debug msg="obtained new client token: AAHNJNJYFhSj2NjfIk9pd6ZHjJgfRzdeN5oJpoWrCjyTXArOuMp0FHfducpMeDN/Hx2Lqqxwe7qzP9ofdYAnKgpoCEL8gbp86gvvN/sHuCw/BuzV9wFZFLEBuihgCTFL3WM1XV3C9zW/VxDS9Bk9af2zsGIC9YnS3ThXWW0QL5w93YwAalUZbzA2skZtxr2BCWbI6TTAReBl5dK0k0J9RgmTrj/ZfOgWrrqJIK5X3LeyF3r2Y6ou" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=debug msg="completed keyexchange" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=debug msg="completed challenge" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=info msg="authenticated AP" username="31************************p4" Aug 31 08:35:49 prmspoti01 go-librespot[2395]: time="2026-08-31T08:35:49+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 08:35:49 prmspoti01 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 08:35:49 prmspoti01 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 08:35:50 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 31 08:35:50 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 08:35:50 prmspoti01 volumio[1603]: info: Received Get System Info Aug 31 08:35:50 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 08:35:50 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 08:35:50 prmspoti01 volumio[1603]: info: Discovery: Getting this device information Aug 31 08:35:50 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioGetState Aug 31 08:35:50 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrack 0 Aug 31 08:35:50 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 08:35:51 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 08:35:51 prmspoti01 volumio[1603]: info: Received Get System Info Aug 31 08:35:51 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 08:35:51 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 08:35:51 prmspoti01 volumio[1603]: info: Discovery: Getting this device information Aug 31 08:35:51 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioGetState Aug 31 08:35:51 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrack 0 Aug 31 08:35:51 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 08:35:52 prmspoti01 volumio[1603]: info: Initializing connection to go-librespot Websocket Aug 31 08:35:52 prmspoti01 volumio[1603]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 08:35:52 prmspoti01 volumio[1603]: info: go-librespot daemon successfully initialized Aug 31 08:35:52 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioGetState Aug 31 08:35:52 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrack 0 Aug 31 08:35:52 prmspoti01 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 31 08:35:52 prmspoti01 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:35:52 prmspoti01 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:35:52 prmspoti01 go-librespot[2404]: go-librespot daemon starting... Aug 31 08:35:52 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:52+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 08:35:52 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:52+02:00" level=debug msg="app state loaded" Aug 31 08:35:52 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:52+02:00" level=debug msg="stored credentials not found" Aug 31 08:35:52 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:52+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 08:35:52 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:52+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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 08:35:52 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:52+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 08:35:52 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:52+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 08:35:52 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:52+02:00" level=info msg="zeroconf server listening on port 38513" Aug 31 08:35:52 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:52+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 08:35:53 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:53+02:00" level=debug msg="obtained new client token: AAGJmYGO1jJs/bnKjjcL+5lieOJ3Uuq8Be/VLBcjIsZ8xfXpyJIQKalWlg8llhZdGDS0646YrCdQXBcKbV3V01sSSMZNe1u7bBxyAMpJHxj0MMZYS64lJgWnx3s+ObKnNIvBd1xZ+4mzd/C1Ib8QquyKYvNY+qZ15oZF0n8KOg2JmmujliBuYCTZh4YbaX9tcjXi6/wzFld0fajgQPcp3Z2SJpiY6N6sn15GRQyVTJ2g/7j3Ncyp" Aug 31 08:35:53 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:53+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 08:35:53 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:53+02:00" level=debug msg="completed keyexchange" Aug 31 08:35:53 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:53+02:00" level=debug msg="completed challenge" Aug 31 08:35:53 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:53+02:00" level=info msg="authenticated AP" username="31************************p4" Aug 31 08:35:53 prmspoti01 go-librespot[2405]: time="2026-08-31T08:35:53+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 08:35:53 prmspoti01 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 08:35:53 prmspoti01 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 08:35:55 prmspoti01 volumio[1603]: info: Initializing connection to go-librespot Websocket Aug 31 08:35:55 prmspoti01 volumio[1603]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 08:35:55 prmspoti01 volumio[1603]: info: Initializing connection to go-librespot Websocket Aug 31 08:35:55 prmspoti01 volumio[1603]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 08:35:56 prmspoti01 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 31 08:35:56 prmspoti01 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:35:56 prmspoti01 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:35:56 prmspoti01 go-librespot[2429]: go-librespot daemon starting... Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=debug msg="app state loaded" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=debug msg="stored credentials not found" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=info msg="zeroconf server listening on port 45749" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=debug msg="obtained new client token: AAGa6GHUko6Foh/ZEhglLRpQPd8cAYuy/5xqXsqnvmIn1+CPo9zZ7L7fZI7mGAmPocqgivfLFUyXaVmtAb9Pez2q7doSDLy1D6GK0Cv/g63KyvNfFQEUJsylcWzAa42HRghB8rjqSn1+5e1o+McXiTAAcaiRKnAgUzLnrkTrWi9DQ2EBFFotqkp+1n8TfV/UMkfLBdRFrrAzRYs1oEpsAkJWoMvV67gFjmGEibJhyXBlcD56AMdMoDM=" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=debug msg="completed keyexchange" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=debug msg="completed challenge" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=info msg="authenticated AP" username="31************************p4" Aug 31 08:35:56 prmspoti01 go-librespot[2430]: time="2026-08-31T08:35:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 08:35:56 prmspoti01 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 08:35:56 prmspoti01 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 08:35:58 prmspoti01 volumio[1603]: info: Initializing connection to go-librespot Websocket Aug 31 08:35:58 prmspoti01 volumio[1603]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 08:35:59 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 31 08:35:59 prmspoti01 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 31 08:35:59 prmspoti01 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:35:59 prmspoti01 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:35:59 prmspoti01 go-librespot[2439]: go-librespot daemon starting... Aug 31 08:35:59 prmspoti01 go-librespot[2440]: time="2026-08-31T08:35:59+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 08:35:59 prmspoti01 go-librespot[2440]: time="2026-08-31T08:35:59+02:00" level=debug msg="app state loaded" Aug 31 08:35:59 prmspoti01 go-librespot[2440]: time="2026-08-31T08:35:59+02:00" level=debug msg="stored credentials not found" Aug 31 08:35:59 prmspoti01 go-librespot[2440]: time="2026-08-31T08:35:59+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 08:35:59 prmspoti01 go-librespot[2440]: time="2026-08-31T08:35:59+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 08:35:59 prmspoti01 go-librespot[2440]: time="2026-08-31T08:35:59+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 08:35:59 prmspoti01 go-librespot[2440]: time="2026-08-31T08:35:59+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 08:35:59 prmspoti01 go-librespot[2440]: time="2026-08-31T08:35:59+02:00" level=info msg="zeroconf server listening on port 33665" Aug 31 08:35:59 prmspoti01 go-librespot[2440]: time="2026-08-31T08:35:59+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 08:36:00 prmspoti01 go-librespot[2440]: time="2026-08-31T08:36:00+02:00" level=debug msg="obtained new client token: AAHzV9/6VAug2kc9X6vyrB5LqB0/vKcSC5rLWjrajkxc+b6UVBF+K7FkWXLm0x+noJ2eOxgvAPX+jLB5eMKyttofFDnKPw5wvI4bG+XwUyq+N8EAaamnq2iRYMoeffxZ19zUvPV3HWhIAIvukMooLN5DbKjDpf6vZrP14+yv4wJUmfDKdTqbnqnDx/sfEuyUp9l281yVW9Bz21yOd5TPm7RgKGCdi033hVEw7b/cwOVv59ClleIz" Aug 31 08:36:00 prmspoti01 go-librespot[2440]: time="2026-08-31T08:36:00+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 31 08:36:00 prmspoti01 go-librespot[2440]: time="2026-08-31T08:36:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 08:36:00 prmspoti01 go-librespot[2440]: time="2026-08-31T08:36:00+02:00" level=debug msg="completed keyexchange" Aug 31 08:36:00 prmspoti01 go-librespot[2440]: time="2026-08-31T08:36:00+02:00" level=debug msg="completed challenge" Aug 31 08:36:00 prmspoti01 go-librespot[2440]: time="2026-08-31T08:36:00+02:00" level=info msg="authenticated AP" username="31************************p4" Aug 31 08:36:00 prmspoti01 go-librespot[2440]: time="2026-08-31T08:36:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 08:36:00 prmspoti01 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 08:36:00 prmspoti01 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 08:36:01 prmspoti01 volumio[1603]: info: Initializing connection to go-librespot Websocket Aug 31 08:36:01 prmspoti01 volumio[1603]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 08:36:03 prmspoti01 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 31 08:36:03 prmspoti01 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:36:03 prmspoti01 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:36:03 prmspoti01 go-librespot[2449]: go-librespot daemon starting... Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=debug msg="app state loaded" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=debug msg="stored credentials not found" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=info msg="zeroconf server listening on port 39607" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=debug msg="obtained new client token: AAGHmDZm2yrwR/z7mm0Cy7uKTkVCbnXNTIhv/C1WW2tOEE9PSWkb+YOxYfN2aVLDVgnCDQunAQMhe1jq5UlNIq8rp/XdklhRPHCqZLAHVRzFrd9Ba7nqQe+WLf9l2LAMclXL3jRuhJu6cO+0xNQMWqvzWzimCX5H8pFAHiYA9VuIIs//aBWZ4HFxOmUjnd677DUTb8EvM0rIcEYy8b0Ki0vaPF7eW3VEB07fPSFZHm7HGyx6r0rcNbo=" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=debug msg="completed keyexchange" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=debug msg="completed challenge" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=info msg="authenticated AP" username="31************************p4" Aug 31 08:36:03 prmspoti01 go-librespot[2464]: time="2026-08-31T08:36:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 08:36:03 prmspoti01 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 08:36:03 prmspoti01 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 08:36:04 prmspoti01 volumio[1603]: info: Initializing connection to go-librespot Websocket Aug 31 08:36:04 prmspoti01 volumio[1603]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 08:36:06 prmspoti01 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 31 08:36:06 prmspoti01 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:36:06 prmspoti01 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 08:36:06 prmspoti01 go-librespot[2473]: go-librespot daemon starting... Aug 31 08:36:06 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:06+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 08:36:06 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:06+02:00" level=debug msg="app state loaded" Aug 31 08:36:06 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:06+02:00" level=debug msg="stored credentials not found" Aug 31 08:36:06 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 08:36:06 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:06+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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 08:36:06 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:06+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 08:36:06 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:06+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 08:36:06 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:06+02:00" level=info msg="zeroconf server listening on port 44775" Aug 31 08:36:06 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:06+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 08:36:07 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:07+02:00" level=debug msg="obtained new client token: AAGBLutjueZaU/QzmIIXRcdpq3px7HKPi4ikooGs9s0Lte2a2rl3bfssOAtzTQQ5lDrvKVE6PgJBC79ZetKt3bX0Btj2h+E55kkd3lD7+WQV+eaZQ8bhHT4p/tAjTd3fQ/2OdrEXsEQcl4/esD0HVnnDwlFR0evz+dI8qQvmkr287ckXtjWJ/xyi5yLGDI8cntBNoYCFW8jYp9aVAK9iAPc1tAzukm8w+Q13GUREFyUozji3/5CAsaY=" Aug 31 08:36:07 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 08:36:07 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:07+02:00" level=debug msg="completed keyexchange" Aug 31 08:36:07 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:07+02:00" level=debug msg="completed challenge" Aug 31 08:36:07 prmspoti01 volumio[1603]: info: Initializing connection to go-librespot Websocket Aug 31 08:36:07 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:07+02:00" level=debug msg="new websocket client" Aug 31 08:36:07 prmspoti01 volumio[1603]: info: Connection to go-librespot Websocket established Aug 31 08:36:07 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:07+02:00" level=info msg="authenticated AP" username="31************************p4" Aug 31 08:36:07 prmspoti01 go-librespot[2474]: time="2026-08-31T08:36:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 08:36:07 prmspoti01 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 08:36:07 prmspoti01 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 08:36:07 prmspoti01 volumio[1603]: info: Connection to go-librespot Websocket closed Aug 31 08:36:08 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 08:36:08 prmspoti01 volumio[1603]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 31 08:36:08 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 31 08:36:08 prmspoti01 volumio[1603]: info: Received Get System Version Aug 31 08:36:08 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 08:36:08 prmspoti01 volumio[1603]: info: Received Get System Info Aug 31 08:36:08 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 08:36:08 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 08:36:08 prmspoti01 volumio[1603]: info: Discovery: Getting this device information Aug 31 08:36:08 prmspoti01 volumio[1603]: info: CoreCommandRouter::volumioGetState Aug 31 08:36:08 prmspoti01 volumio[1603]: info: CorePlayQueue::getTrack 0 Aug 31 08:36:08 prmspoti01 volumio[1603]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 08:36:10 prmspoti01 volumio[1603]: info: Getting Spotify volume Aug 31 08:36:10 prmspoti01 volumio[1603]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 08:36:10 prmspoti01 volumio[1603]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 08:36:10 prmspoti01 volumio[1603]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 08:36:10 prmspoti01 volumio[1603]: errno: -111, Aug 31 08:36:10 prmspoti01 volumio[1603]: code: 'ECONNREFUSED', Aug 31 08:36:10 prmspoti01 volumio[1603]: syscall: 'connect', Aug 31 08:36:10 prmspoti01 volumio[1603]: address: '127.0.0.1', Aug 31 08:36:10 prmspoti01 volumio[1603]: port: 9879, Aug 31 08:36:10 prmspoti01 volumio[1603]: response: undefined Aug 31 08:36:10 prmspoti01 volumio[1603]: } Aug 31 08:36:10 prmspoti01 volumio[1603]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 08:36:10 prmspoti01 sudo[2497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 08:35' Aug 31 08:36:10 prmspoti01 sudo[2497]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"