Aug 28 22:03:58 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:58.464+01:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s Aug 28 22:03:58 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:58.623+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=http://pushupdates.volumio.org duration=151.286321ms Aug 28 22:03:58 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:58.664+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=199.413856ms Aug 28 22:03:58 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:58.768+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=https://securetoken.googleapis.com duration=300.91946ms Aug 28 22:03:58 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:58.771+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=https://www.googleapis.com duration=306.435205ms Aug 28 22:03:58 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:58.831+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=360.225934ms Aug 28 22:03:58 volumio volumio[1253]: verbose: New Socket.io Connection to 192.168.1.82 from 192.168.1.208 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Aug 28 22:03:58 volumio volumio[1253]: info: CoreCommandRouter::volumioGetState Aug 28 22:03:58 volumio volumio[1253]: info: CorePlayQueue::getTrack 0 Aug 28 22:03:58 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:58.925+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=454.497508ms Aug 28 22:03:58 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:58.933+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=461.311225ms Aug 28 22:03:58 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:58.933+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=https://functions.volumio.cloud duration=461.365288ms Aug 28 22:03:58 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 28 22:03:58 volumio volumio[1253]: info: Listing playlists Aug 28 22:03:58 volumio volumio[1253]: info: CoreCommandRouter::volumioGetQueue Aug 28 22:03:58 volumio volumio[1253]: info: CoreStateMachine::getQueue Aug 28 22:03:58 volumio volumio[1253]: info: CorePlayQueue::getQueue Aug 28 22:03:59 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:59.028+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=https://database.volumio.cloud duration=555.324412ms Aug 28 22:03:59 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:59.054+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=https://functions.volumio.cloud duration=584.111475ms Aug 28 22:03:59 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:59.074+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=http://cddb.volumio.org duration=602.881736ms Aug 28 22:03:59 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:59.144+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=https://google.com duration=679.786958ms Aug 28 22:03:59 volumio volumio5-onboarding[1405]: time=2026-08-28T22:03:59.274+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.208:56885,00:00:00:00:00:00%01 @ 0x30a10e0" latency=37.365809ms timeout=10s endpoint=http://plugins.volumio.org duration=801.263871ms Aug 28 22:04:00 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 22:04:00 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 22:04:00 volumio volumio[1253]: info: Discovery: Getting this device information Aug 28 22:04:00 volumio volumio[1253]: info: CoreCommandRouter::volumioGetState Aug 28 22:04:00 volumio volumio[1253]: info: CorePlayQueue::getTrack 0 Aug 28 22:04:00 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 22:04:00 volumio volumio[1253]: verbose: New Socket.io Connection to 192.168.1.82:3000 from 192.168.1.208 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Aug 28 22:04:00 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 22:04:00 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 22:04:01 volumio volumio[1253]: info: CoreCommandRouter::volumioPlay Aug 28 22:04:01 volumio volumio[1253]: info: CoreStateMachine::play index 5 Aug 28 22:04:01 volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 28 22:04:01 volumio volumio[1253]: info: CoreStateMachine::stop Aug 28 22:04:01 volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 28 22:04:01 volumio volumio[1253]: info: CoreStateMachine::play index undefined Aug 28 22:04:01 volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 28 22:04:01 volumio volumio[1253]: info: CorePlayQueue::getTrack 5 Aug 28 22:04:01 volumio volumio[1253]: info: CoreStateMachine::startPlaybackTimer Aug 28 22:04:01 volumio volumio[1253]: info: CorePlayQueue::getTrack 5 Aug 28 22:04:01 volumio volumio[1253]: info: [1787951041176] ControllerSpotify::clearAddPlayTrack Aug 28 22:04:01 volumio volumio[1253]: info: Sending Spotify command with payload to local API: /player/play Aug 28 22:04:03 volumio volumio[1253]: info: CoreCommandRouter::volumioGetVisibleSources Aug 28 22:04:03 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 22:04:07 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 28 22:04:07 volumio volumio[1253]: info: Received Get System Info Aug 28 22:04:07 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 28 22:04:07 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 28 22:04:07 volumio volumio[1253]: info: Discovery: Getting this device information Aug 28 22:04:07 volumio volumio[1253]: info: CoreCommandRouter::volumioGetState Aug 28 22:04:07 volumio volumio[1253]: info: CorePlayQueue::getTrack 5 Aug 28 22:04:07 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 28 22:04:09 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 28 22:04:09 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 28 22:04:16 volumio volumio[1253]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 28 22:04:22 volumio volumio[1253]: info: Received OAUTH Data Aug 28 22:04:22 volumio volumio[1253]: info: Executing Spotify Oauth Login Aug 28 22:04:22 volumio volumio[1253]: info: Saving Spotify Refresh Token Aug 28 22:04:22 volumio volumio[1253]: info: New Spotify access tokenBQDdQHdkYS... Aug 28 22:04:22 volumio volumio[1253]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 28 22:04:22 volumio sudo[5084]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 28 22:04:22 volumio sudo[5084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 22:04:22 volumio sudo[5084]: pam_unix(sudo:session): session closed for user root Aug 28 22:04:22 volumio sudo[5086]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 28 22:04:22 volumio sudo[5086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 22:04:22 volumio sudo[5086]: pam_unix(sudo:session): session closed for user root Aug 28 22:04:22 volumio volumio[1253]: verbose: New Socket.io Connection to 192.168.1.82 from 192.168.1.208 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Aug 28 22:04:22 volumio volumio[1253]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 28 22:04:22 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 28 22:04:22 volumio volumio[1253]: info: CoreCommandRouter::volumioGetState Aug 28 22:04:22 volumio volumio[1253]: info: CorePlayQueue::getTrack 5 Aug 28 22:04:22 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 28 22:04:22 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 28 22:04:22 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 28 22:04:22 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 28 22:04:22 volumio volumio[1253]: SPOTIFY: User informations: {"account_id":"wEVuXsj6qA","country":"GB","display_name":"andymcdonald1962","email":"andrew_j_mcdonald@btinternet.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/andymcdonald1962"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/andymcdonald1962","id":"andymcdonald1962","images":[],"product":"premium","type":"user","uri":"spotify:user:andymcdonald1962"} Aug 28 22:04:22 volumio volumio[1253]: info: Creating Spotify config file Aug 28 22:04:22 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 22:04:22 volumio volumio[1253]: info: Spotify config file written Aug 28 22:04:22 volumio sudo[5091]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 28 22:04:22 volumio sudo[5091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 22:04:22 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 28 22:04:22 volumio systemd[1]: go-librespot-daemon.service: Killing process 1529 (go-librespot) with signal SIGKILL. Aug 28 22:04:22 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 28 22:04:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 22:04:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 22:04:22 volumio go-librespot[5093]: go-librespot daemon starting... Aug 28 22:04:22 volumio volumio[1253]: info: Connection to go-librespot Websocket closed Aug 28 22:04:22 volumio sudo[5091]: pam_unix(sudo:session): session closed for user root Aug 28 22:04:22 volumio go-librespot[5094]: time="2026-08-28T22:04:22+01:00" level=info msg="running go-librespot 0.7.1" Aug 28 22:04:22 volumio go-librespot[5094]: time="2026-08-28T22:04:22+01:00" level=debug msg="app state loaded" Aug 28 22:04:22 volumio go-librespot[5094]: time="2026-08-28T22:04:22+01:00" level=debug msg="stored credentials not found" Aug 28 22:04:22 volumio go-librespot[5094]: time="2026-08-28T22:04:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 22:04:22 volumio volumio[1253]: info: New Spotify access tokenBQATVFmCqR... Aug 28 22:04:22 volumio volumio[1253]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 28 22:04:22 volumio volumio[1253]: SPOTIFY: User informations: {"account_id":"wEVuXsj6qA","country":"GB","display_name":"andymcdonald1962","email":"andrew_j_mcdonald@btinternet.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/andymcdonald1962"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/andymcdonald1962","id":"andymcdonald1962","images":[],"product":"premium","type":"user","uri":"spotify:user:andymcdonald1962"} Aug 28 22:04:22 volumio volumio[1253]: info: Spotify Successfully logged in Aug 28 22:04:22 volumio volumio[1253]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 28 22:04:22 volumio volumio[1253]: info: [1787951062948] CoreMusicLibrary::Adding element Spotify Aug 28 22:04:22 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 22:04:22 volumio volumio[1253]: Cannot find translation for source Spotify Aug 28 22:04:22 volumio go-librespot[5094]: time="2026-08-28T22:04:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 22:04:22 volumio go-librespot[5094]: time="2026-08-28T22:04:22+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 22:04:22 volumio go-librespot[5094]: time="2026-08-28T22:04:22+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 22:04:22 volumio go-librespot[5094]: time="2026-08-28T22:04:22+01:00" level=info msg="zeroconf server listening on port 42193" Aug 28 22:04:22 volumio go-librespot[5094]: time="2026-08-28T22:04:22+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 22:04:23 volumio go-librespot[5094]: time="2026-08-28T22:04:23+01:00" level=debug msg="obtained new client token: AAGKNskV7tQQsJlhTJfy8ux223Tet3U+LOu8aqYWpHUGsehN4P2vrxwxrIfwQg+obx76bDx859QMuyp9JkihlKhY5mKlc5fno3rzppe8T0HdJx6MDSYCQTxomclAjSV/j4vhrlyxjJMNUn226XQw+yNKeM5WQ5WzI7TW0EdbEjvpa9MJ4vN8v0vp7QPA3zJcPElOVSnxcUnJyhVOAVB0wbENXDmKMJZECutOsP58LWuuiaK4mSt2xos=" Aug 28 22:04:23 volumio go-librespot[5094]: time="2026-08-28T22:04:23+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 22:04:23 volumio go-librespot[5094]: time="2026-08-28T22:04:23+01:00" level=debug msg="completed keyexchange" Aug 28 22:04:23 volumio go-librespot[5094]: time="2026-08-28T22:04:23+01:00" level=debug msg="completed challenge" Aug 28 22:04:23 volumio go-librespot[5094]: time="2026-08-28T22:04:23+01:00" level=info msg="authenticated AP" username="an************62" Aug 28 22:04:23 volumio go-librespot[5094]: time="2026-08-28T22:04:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 22:04:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 22:04:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 22:04:25 volumio volumio[1253]: info: Initializing connection to go-librespot Websocket Aug 28 22:04:25 volumio volumio[1253]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 22:04:25 volumio volumio[1253]: info: go-librespot daemon successfully initialized Aug 28 22:04:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 28 22:04:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 22:04:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 22:04:26 volumio go-librespot[5103]: go-librespot daemon starting... Aug 28 22:04:26 volumio go-librespot[5104]: time="2026-08-28T22:04:26+01:00" level=info msg="running go-librespot 0.7.1" Aug 28 22:04:26 volumio go-librespot[5104]: time="2026-08-28T22:04:26+01:00" level=debug msg="app state loaded" Aug 28 22:04:26 volumio go-librespot[5104]: time="2026-08-28T22:04:26+01:00" level=debug msg="stored credentials not found" Aug 28 22:04:26 volumio go-librespot[5104]: time="2026-08-28T22:04:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 22:04:26 volumio go-librespot[5104]: time="2026-08-28T22:04:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 22:04:26 volumio go-librespot[5104]: time="2026-08-28T22:04:26+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 22:04:26 volumio go-librespot[5104]: time="2026-08-28T22:04:26+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 22:04:26 volumio go-librespot[5104]: time="2026-08-28T22:04:26+01:00" level=info msg="zeroconf server listening on port 37605" Aug 28 22:04:26 volumio go-librespot[5104]: time="2026-08-28T22:04:26+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 22:04:27 volumio go-librespot[5104]: time="2026-08-28T22:04:27+01:00" level=debug msg="obtained new client token: AAHk/aJGIPN0L7eKW0gxMX8Gk1o1StIWnybs5mxCj5LNA0wjs+9ZW9foAGTq4IGi0i6ukLQmjkvh2/V5U7wcTvTyW0iU2l/DNnGAyYw4eUqA413bUGarY4V7sS7bHTX5NJx33XDLzA9XIEF34o1qcRaaJQJqD95hF3Ioj8k0s9qBC7QdjUfZ+45m06Ne7SS5FjEiHxkmhDIn3c8gHrP4o8q2IBo8ywM9EoXhkQhlrxBwT2S8X5cL9oU=" Aug 28 22:04:27 volumio go-librespot[5104]: time="2026-08-28T22:04:27+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 22:04:27 volumio go-librespot[5104]: time="2026-08-28T22:04:27+01:00" level=debug msg="completed keyexchange" Aug 28 22:04:27 volumio go-librespot[5104]: time="2026-08-28T22:04:27+01:00" level=debug msg="completed challenge" Aug 28 22:04:27 volumio go-librespot[5104]: time="2026-08-28T22:04:27+01:00" level=info msg="authenticated AP" username="an************62" Aug 28 22:04:27 volumio go-librespot[5104]: time="2026-08-28T22:04:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 22:04:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 22:04:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 22:04:28 volumio volumio[1253]: info: CoreCommandRouter::volumioGetVisibleSources Aug 28 22:04:28 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 28 22:04:28 volumio volumio[1253]: info: CoreCommandRouter::volumioGetQueue Aug 28 22:04:28 volumio volumio[1253]: info: CoreStateMachine::getQueue Aug 28 22:04:28 volumio volumio[1253]: info: CorePlayQueue::getQueue Aug 28 22:04:28 volumio volumio[1253]: info: Listing playlists Aug 28 22:04:28 volumio volumio[1253]: info: Initializing connection to go-librespot Websocket Aug 28 22:04:28 volumio volumio[1253]: info: Initializing connection to go-librespot Websocket Aug 28 22:04:28 volumio volumio[1253]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 22:04:28 volumio volumio[1253]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 22:04:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 28 22:04:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 22:04:30 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 28 22:04:30 volumio volumio[1253]: info: In handleBrowseUri, curUri=spotify Aug 28 22:04:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 22:04:30 volumio go-librespot[5113]: go-librespot daemon starting... Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=info msg="running go-librespot 0.7.1" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=debug msg="app state loaded" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=debug msg="stored credentials not found" Aug 28 22:04:30 volumio volumio[1253]: info: Preload queue cleared Aug 28 22:04:30 volumio volumio[1253]: info: Preload queue cleared Aug 28 22:04:30 volumio volumio[1253]: info: Preload queue cleared Aug 28 22:04:30 volumio volumio[1253]: info: Preload queue cleared Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=info msg="zeroconf server listening on port 36577" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=debug msg="obtained new client token: AAFncUVMw5+C197xfV9W8YtGB1G2F09RvzKYOCPNM1xlhdZz+3GPTQ6fR4asfU/kArQDwM5Q39PKcrg5XGf5r6DFcG4IyNYbCWDhi9+q0EPx35yNDGnPEktYZ+MNkU1WXN3z76yDltjzcutX0fu2VA4wrU94oL+lM2IEO6ATcyiL1hIdyr0OFoPNjYmCvMbfinbOuaAey6+yrDWqOVeZJZfOVNGSl776v4wc7/hvB7LJSOMCDzhDvCXF0g==" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=debug msg="completed keyexchange" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=debug msg="completed challenge" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=info msg="authenticated AP" username="an************62" Aug 28 22:04:30 volumio go-librespot[5128]: time="2026-08-28T22:04:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 22:04:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 22:04:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 22:04:31 volumio volumio[1253]: info: Initializing connection to go-librespot Websocket Aug 28 22:04:31 volumio volumio[1253]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 22:04:33 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 28 22:04:33 volumio volumio[1253]: info: In handleBrowseUri, curUri=spotify/playlists Aug 28 22:04:33 volumio volumio[1253]: info: Preload queue cleared Aug 28 22:04:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 28 22:04:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 22:04:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 22:04:34 volumio go-librespot[5138]: go-librespot daemon starting... Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=info msg="running go-librespot 0.7.1" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=debug msg="app state loaded" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=debug msg="stored credentials not found" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=info msg="zeroconf server listening on port 33047" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=debug msg="obtained new client token: AAHVOcFGjRSQ/DG4c0JdAzSfBBsH2lCq/RjBVwA3ktforOcCrehwDl3ggvV8Aijvc2AcPF9yc+mJtyVmxkdOo6wOMduXqayk8xIo/wOxRKQfQEj5USbSMCDJClX+QIdpooW/3L7u5vwAXsNCTDAr3vFrWM72O4W5tojF+tF7yLCTY33UfjlF85EGXZTpYY3mMob//7hjNpbajSfYtjszLja+M3J9zz3hshxvQhEJ9myIP87BBWO4DkMw+g==" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=debug msg="completed keyexchange" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=debug msg="completed challenge" Aug 28 22:04:34 volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 28 22:04:34 volumio volumio[1253]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:37i9dQZF1EQn4jwNIohw50 Aug 28 22:04:34 volumio volumio[1253]: info: Initializing connection to go-librespot Websocket Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=info msg="authenticated AP" username="an************62" Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=debug msg="new websocket client" Aug 28 22:04:34 volumio volumio[1253]: info: Connection to go-librespot Websocket established Aug 28 22:04:34 volumio go-librespot[5139]: time="2026-08-28T22:04:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 28 22:04:34 volumio volumio[1253]: info: Connection to go-librespot Websocket closed Aug 28 22:04:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 28 22:04:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 28 22:04:36 volumio volumio[1253]: info: Preload queue cleared Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:4xlEKYv7HmC8zXoJIbpZKM Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:28cnXtME493VX9NOw9cIUh Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:6PwjJ58I4t7Mae9xfZ9l9v Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:0COqiPhxzoWICwFCS4eZcp Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:2x8evxqUlF0eRabbW2JBJd Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:2OARIMw1hpehr86Iwmv04c Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:75D3n6wnFQmu1HVmLAlWM4 Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:5A1FmxbYVRZKy4nc16MAue Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:4zOfy9kqJlG0ZXvcaSh4gv Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:6dnco8haegnJYtylV26cBq Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:1bCmvezFg5MRcENzCGG1Cy Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:42T2QQv3xgBlpQxaSP7lnK Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:0Qv7xi6uPSqH2k82tOkGSt Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:1vxw6aYJls2oq3gW0DujAo Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:1L5tZi0izXsi5Kk5OJf4W0 Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:4vAD6goBKmPPUKHZ8XfDtL Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:329qJlNVgKWWr0WdYwxZxM Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:5Fpe2DMiC7BujUQeZFY6IV Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:6ZOBP3NvffbU4SZcrnt1k6 Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:6pacvUlFUY5YmDvDZSOnqD Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:3CB2tntOz9JudpNv5Fa7Kx Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:1gVVSmhWjci8l9Vrsl6HaS Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:3APHT3KjbHi9OllkVQsuXF Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:7kzKAuUzOITUauHAhoMoxA Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:4dyx5SzxPPaD8xQIid5Wjj Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:4E2gdBRKC12MJWFUOkH0UN Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:5dcwiQFqn0mTcWewYIv7MV Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:003vvx7Niy0yvhvHt4a68B Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:0gmbgwZ8iqyMPmXefof8Yf Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:2zzLRQ78kKfPTx8FJQCdC2 Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:20I8RduZC2PWMWTDCZuuAN Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:2sgBTNHz9ckmqj3rx3ez4M Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:385jG5syLcYoplR9Fp510H Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:2TYC9SaRhYypUQzB1ZVTG2 Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:0v1XpBHnsbkCn7iJ9Ucr1l Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:7tCHpjktA50ihtkLz6bAnn Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:6TfBA04WJ3X1d1wXhaCFVT Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:6y20BV5L33R8YXM0YuI38N Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:2bfGNzdiRa1jXZRdfssSzR Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:5it9RIRXDwiLpJKdce6Z7e Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:1jJci4qxiYcOHhQR247rEU Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:1sooHNTnK4CAn7HLTU3Q59 Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:4rr0gWiMrF4sOIefs3IEvZ Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:7f1X6tauagdeqpfNuNOYWr Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:0cPFDJKfL1CRsIirnN3mgW Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:1Tlb88J33fwG4EiZOFfhvY Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:0gzqZ9d1jIKo9psEIthwXe Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:2dhwJNH50XJWS3tCKVWKtD Aug 28 22:04:36 volumio volumio[1253]: info: Preloading song: spotify:track:27L8sESb3KR79asDUBu8nW Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:4xlEKYv7HmC8zXoJIbpZKM in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:4xlEKYv7HmC8zXoJIbpZKM Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:28cnXtME493VX9NOw9cIUh in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:28cnXtME493VX9NOw9cIUh Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:6PwjJ58I4t7Mae9xfZ9l9v in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:6PwjJ58I4t7Mae9xfZ9l9v Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:0COqiPhxzoWICwFCS4eZcp in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:0COqiPhxzoWICwFCS4eZcp Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:2x8evxqUlF0eRabbW2JBJd in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:2x8evxqUlF0eRabbW2JBJd Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:2OARIMw1hpehr86Iwmv04c in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:2OARIMw1hpehr86Iwmv04c Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:75D3n6wnFQmu1HVmLAlWM4 in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:75D3n6wnFQmu1HVmLAlWM4 Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:5A1FmxbYVRZKy4nc16MAue in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:5A1FmxbYVRZKy4nc16MAue Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4xlEKYv7HmC8zXoJIbpZKM","service":"spop","name":"Steady, As She Goes","artist":"The Raconteurs","album":"Broken Boy Soldiers","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b273aaafcdc8e35209dc99554017","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:4zOfy9kqJlG0ZXvcaSh4gv in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:4zOfy9kqJlG0ZXvcaSh4gv Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0COqiPhxzoWICwFCS4eZcp","service":"spop","name":"Bring Me To Life","artist":"Evanescence","album":"Fallen","type":"song","duration":235,"albumart":"https://i.scdn.co/image/ab67616d0000b27325f49ab23f0ec6332efef432","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6PwjJ58I4t7Mae9xfZ9l9v","service":"spop","name":"Somebody Told Me","artist":"The Killers","album":"Hot Fuss","type":"song","duration":197,"albumart":"https://i.scdn.co/image/ab67616d0000b273ccdddd46119a4ff53eaf1f5d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:28cnXtME493VX9NOw9cIUh","service":"spop","name":"Hurt","artist":"Johnny Cash","album":"American IV: The Man Comes Around","type":"song","duration":216,"albumart":"https://i.scdn.co/image/ab67616d0000b2736f4f62da3d811b6501a69ffa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2OARIMw1hpehr86Iwmv04c","service":"spop","name":"Peggy Sue","artist":"Buddy Holly","album":"Buddy Holly","type":"song","duration":150,"albumart":"https://i.scdn.co/image/ab67616d0000b27358816b5b546bdc2c0e7f6416","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:6dnco8haegnJYtylV26cBq in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:6dnco8haegnJYtylV26cBq Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:1bCmvezFg5MRcENzCGG1Cy in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:1bCmvezFg5MRcENzCGG1Cy Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:75D3n6wnFQmu1HVmLAlWM4","service":"spop","name":"I Predict A Riot","artist":"Kaiser Chiefs","album":"Employment","type":"song","duration":233,"albumart":"https://i.scdn.co/image/ab67616d0000b273ff04d490d9d10ea687f38f36","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2x8evxqUlF0eRabbW2JBJd","service":"spop","name":"Fluorescent Adolescent","artist":"Arctic Monkeys","album":"Favourite Worst Nightmare","type":"song","duration":183,"albumart":"https://i.scdn.co/image/ab67616d0000b273b1f8da74f225fa1225cdface","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:42T2QQv3xgBlpQxaSP7lnK in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:42T2QQv3xgBlpQxaSP7lnK Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4zOfy9kqJlG0ZXvcaSh4gv","service":"spop","name":"Viva La Vida","artist":"Coldplay","album":"Viva La Vida or Death and All His Friends","type":"song","duration":242,"albumart":"https://i.scdn.co/image/ab67616d0000b273be592342bbc8e3bfce593b16","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5A1FmxbYVRZKy4nc16MAue","service":"spop","name":"Sex on Fire","artist":"Kings of Leon","album":"Only By The Night","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b27379b30684a8e0dd83917c7cc5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:0Qv7xi6uPSqH2k82tOkGSt in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:0Qv7xi6uPSqH2k82tOkGSt Aug 28 22:04:36 volumio volumio[1253]: info: Exploding uri spotify:track:1vxw6aYJls2oq3gW0DujAo in service spop Aug 28 22:04:36 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:1vxw6aYJls2oq3gW0DujAo Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:42T2QQv3xgBlpQxaSP7lnK","service":"spop","name":"One Last Breath","artist":"Creed","album":"Weathered","type":"song","duration":238,"albumart":"https://i.scdn.co/image/ab67616d0000b273a32f2ae4dade83e0d7a294f4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:1L5tZi0izXsi5Kk5OJf4W0 in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:1L5tZi0izXsi5Kk5OJf4W0 Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6dnco8haegnJYtylV26cBq","service":"spop","name":"Islands In the Stream","artist":"Dolly Parton","album":"Greatest Hits","type":"song","duration":251,"albumart":"https://i.scdn.co/image/ab67616d0000b273f4b9ecd2ef53484ca3206f82","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1bCmvezFg5MRcENzCGG1Cy","service":"spop","name":"Chelsea Dagger","artist":"The Fratellis","album":"Costello Music","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b273adba877024420660db2f124e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0Qv7xi6uPSqH2k82tOkGSt","service":"spop","name":"Mad World","artist":"Tears For Fears","album":"The Hurting","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b27345546ed4af1a0d4c58a8ff50","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:4vAD6goBKmPPUKHZ8XfDtL in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:4vAD6goBKmPPUKHZ8XfDtL Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1vxw6aYJls2oq3gW0DujAo","service":"spop","name":"Crazy","artist":"Gnarls Barkley","album":"St. Elsewhere","type":"song","duration":177,"albumart":"https://i.scdn.co/image/ab67616d0000b273ceb0b3423d21e3da43c58b0b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:329qJlNVgKWWr0WdYwxZxM in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:329qJlNVgKWWr0WdYwxZxM Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","service":"spop","name":"Rehab","artist":"Amy Winehouse","album":"Back To Black","type":"song","duration":213,"albumart":"https://i.scdn.co/image/ab67616d0000b273dc65d5638a3de4a0bdf3c05f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:5Fpe2DMiC7BujUQeZFY6IV in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:5Fpe2DMiC7BujUQeZFY6IV Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4vAD6goBKmPPUKHZ8XfDtL","service":"spop","name":"The Seeker","artist":"The Who","album":"BBC Sessions","type":"song","duration":186,"albumart":"https://i.scdn.co/image/ab67616d0000b273ce4074f73f07aa2aab3218ec","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:6ZOBP3NvffbU4SZcrnt1k6 in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:6ZOBP3NvffbU4SZcrnt1k6 Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:329qJlNVgKWWr0WdYwxZxM","service":"spop","name":"Have You Ever Seen The Rain (John's Version)","artist":"John Fogerty","album":"Legacy: the Creedence Clearwater Revival years (John's Version)","type":"song","duration":162,"albumart":"https://i.scdn.co/image/ab67616d0000b273051a6ce3137e884e9e6c2de9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:6pacvUlFUY5YmDvDZSOnqD in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:6pacvUlFUY5YmDvDZSOnqD Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:3CB2tntOz9JudpNv5Fa7Kx in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:3CB2tntOz9JudpNv5Fa7Kx Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5Fpe2DMiC7BujUQeZFY6IV","service":"spop","name":"A Little Less Conversation","artist":"Elvis Presley","album":"Almost in Love","type":"song","duration":120,"albumart":"https://i.scdn.co/image/ab67616d0000b273550ad54dee11f46a1187ca9b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:1gVVSmhWjci8l9Vrsl6HaS in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:1gVVSmhWjci8l9Vrsl6HaS Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6ZOBP3NvffbU4SZcrnt1k6","service":"spop","name":"Kryptonite","artist":"3 Doors Down","album":"The Better Life","type":"song","duration":233,"albumart":"https://i.scdn.co/image/ab67616d0000b2732868c4713a3912fd476b42f1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:3APHT3KjbHi9OllkVQsuXF in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:3APHT3KjbHi9OllkVQsuXF Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:7kzKAuUzOITUauHAhoMoxA in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:7kzKAuUzOITUauHAhoMoxA Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3CB2tntOz9JudpNv5Fa7Kx","service":"spop","name":"Rebel Yell - Edit","artist":"Billy Idol","album":"Rebel Yell","type":"song","duration":226,"albumart":"https://i.scdn.co/image/ab67616d0000b273175a92be1b516edd4a7e1b72","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6pacvUlFUY5YmDvDZSOnqD","service":"spop","name":"Runaway","artist":"Traveling Wilburys","album":"The Traveling Wilburys Collection","type":"song","duration":150,"albumart":"https://i.scdn.co/image/ab67616d0000b2736a9fad2833676800472d4b9f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1gVVSmhWjci8l9Vrsl6HaS","service":"spop","name":"Vertigo","artist":"U2","album":"How To Dismantle An Atomic Bomb","type":"song","duration":193,"albumart":"https://i.scdn.co/image/ab67616d0000b273c1c82c472d758f4945ac15a8","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:4dyx5SzxPPaD8xQIid5Wjj in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:4dyx5SzxPPaD8xQIid5Wjj Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:4E2gdBRKC12MJWFUOkH0UN in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:4E2gdBRKC12MJWFUOkH0UN Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:3dPQuX8Gs42Y7b454ybpMR in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:3dPQuX8Gs42Y7b454ybpMR Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7kzKAuUzOITUauHAhoMoxA","service":"spop","name":"Last Nite","artist":"The Strokes","album":"Is This It","type":"song","duration":193,"albumart":"https://i.scdn.co/image/ab67616d0000b273a388a3f20d1bf2123249cc79","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4dyx5SzxPPaD8xQIid5Wjj","service":"spop","name":"Young Folks","artist":"Peter Bjorn and John","album":"Writer's Block","type":"song","duration":276,"albumart":"https://i.scdn.co/image/ab67616d0000b2739cf4ac84b224a02f34d2e4f6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Exploding uri spotify:track:5dcwiQFqn0mTcWewYIv7MV in service spop Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: EXPLODING URI:spotify:track:5dcwiQFqn0mTcWewYIv7MV Aug 28 22:04:37 volumio volumio[1253]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4E2gdBRKC12MJWFUOkH0UN","service":"spop","name":"Dreadlock Holiday","artist":"10cc","album":"20th Century Masters: The Millennium Collection: Best Of 10CC","type":"song","duration":301,"albumart":"https://i.scdn.co/image/ab67616d0000b273b3241dc75e8ffc1e9cd12091","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 28 22:04:37 volumio volumio[1253]: info: Getting Spotify volume Aug 28 22:04:37 volumio volumio[1253]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 22:04:37 volumio volumio[1253]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 28 22:04:37 volumio volumio[1253]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 28 22:04:37 volumio volumio[1253]: errno: -111, Aug 28 22:04:37 volumio volumio[1253]: code: 'ECONNREFUSED', Aug 28 22:04:37 volumio volumio[1253]: syscall: 'connect', Aug 28 22:04:37 volumio volumio[1253]: address: '127.0.0.1', Aug 28 22:04:37 volumio volumio[1253]: port: 9879, Aug 28 22:04:37 volumio volumio[1253]: response: undefined Aug 28 22:04:37 volumio volumio[1253]: } Aug 28 22:04:37 volumio volumio[1253]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 22:04:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 28 22:04:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 28 22:04:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 28 22:04:38 volumio go-librespot[5162]: go-librespot daemon starting... Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=info msg="running go-librespot 0.7.1" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=debug msg="app state loaded" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=debug msg="stored credentials not found" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=info msg="zeroconf server listening on port 33531" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=debug msg="obtained new client token: AAH5h7XZ/zPaos5tttVIroysQsl5YqD9h62insy9mzY9eYXXGT9CBTweJKQxAcnwh0AQTsBs3h3UxOa7VrtmcU6/pcqmNK3F9loXahFZjvllzPK8hRQTLY00vIvOyw9UxMy0nREmB2uu5hE18g6kfWDl0xcFUAmT6cyFDnfYD6PL6EmnIpxhRJiDd7tPy3sCwFHOz0KVdzbOWuDbyPE84Z7S2AWz9Nsvhd7aubjJihNQhKnOp8Kn1IHfwQ==" Aug 28 22:04:38 volumio sudo[5174]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-28 22:03' Aug 28 22:04:38 volumio sudo[5174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=debug msg="completed keyexchange" Aug 28 22:04:38 volumio go-librespot[5163]: time="2026-08-28T22:04:38+01:00" level=debug msg="completed challenge" 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"