Aug 29 17:29:01 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:01 basement-music volumio[1480]: info: [1788038941732] ControllerPandora::removeTrack Aug 29 17:29:01 basement-music volumio[1480]: info: [1788038941732] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=1813399138380395345 at queue index: -1 Aug 29 17:29:02 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:02 basement-music volumio[1480]: info: [1788038942085] ControllerPandora::removeTrack Aug 29 17:29:02 basement-music volumio[1480]: info: [1788038942085] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=1667643616406651741 at queue index: -1 Aug 29 17:29:04 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetState Aug 29 17:29:05 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:05 basement-music volumio[1480]: info: CorePlayQueue::getTrack 11 Aug 29 17:29:05 basement-music volumio[1480]: info: [1788038945316] ControllerPandora::ExpireOldTracks::reaper Aug 29 17:29:05 basement-music volumio[1480]: info: [1788038945316] [Pandora] ExpireOldTracks::reaper: No victims found: Expiring zero tracks. Don't worry -- Jason will return. Aug 29 17:29:07 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:07 basement-music volumio[1480]: info: [1788038947311] ControllerPandora::removeTrack Aug 29 17:29:07 basement-music volumio[1480]: info: [1788038947311] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=3082397900383431901 at queue index: -1 Aug 29 17:29:07 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:07 basement-music volumio[1480]: info: [1788038947462] ControllerPandora::removeTrack Aug 29 17:29:07 basement-music volumio[1480]: info: [1788038947463] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=1667643616406651741 at queue index: -1 Aug 29 17:29:07 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 17:29:07 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 17:29:11 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 27. Aug 29 17:29:11 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:29:11 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:29:11 basement-music upmpdcli[2422]: Could not open config: /tmp/upmpdcli.conf Aug 29 17:29:11 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:11 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 17:29:12 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:12 basement-music volumio[1480]: info: [1788038952085] ControllerPandora::removeTrack Aug 29 17:29:12 basement-music volumio[1480]: info: CoreStateMachine::removeQueueItem Aug 29 17:29:12 basement-music volumio[1480]: info: CorePlayQueue::removeQueueItem 10 Aug 29 17:29:12 basement-music volumio[1480]: info: CorePlayQueue::saveQueue Aug 29 17:29:12 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushQueue Aug 29 17:29:12 basement-music volumio[1480]: info: [1788038952111] [Pandora] removeTrack: Removed track with uri: /pandora/stationToken=202462973774539151trackId=8979009458702193333 at queue index: 10 Aug 29 17:29:12 basement-music volumio[1480]: info: ControllerMpd::getState Aug 29 17:29:12 basement-music volumio[1480]: verbose: ControllerMpd::sendMpdCommand status Aug 29 17:29:12 basement-music volumio[1480]: info: sendMpdCommand status took 65 milliseconds Aug 29 17:29:12 basement-music volumio[1480]: verbose: ControllerMpd::parseState Aug 29 17:29:12 basement-music volumio[1480]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 17:29:12 basement-music volumio[1480]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 29 17:29:12 basement-music volumio[1480]: verbose: ControllerMpd::parseTrackInfo Aug 29 17:29:12 basement-music volumio[1480]: info: [1788038952181] ControllerPandora::pushState Aug 29 17:29:12 basement-music volumio[1480]: info: CoreCommandRouter::servicePushState Aug 29 17:29:12 basement-music volumio[1480]: info: CorePlayQueue::getTrack 10 Aug 29 17:29:12 basement-music volumio[1480]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received pandora Aug 29 17:29:12 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 29 17:29:17 basement-music volumio[1480]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 29 17:29:17 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:17 basement-music volumio[1480]: info: [1788038957311] ControllerPandora::removeTrack Aug 29 17:29:17 basement-music volumio[1480]: info: [1788038957312] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=1667643616406651741 at queue index: -1 Aug 29 17:29:25 basement-music volumio[1480]: info: Received OAUTH Data Aug 29 17:29:25 basement-music volumio[1480]: info: Executing Spotify Oauth Login Aug 29 17:29:25 basement-music volumio[1480]: info: Saving Spotify Refresh Token Aug 29 17:29:25 basement-music sudo[2442]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 17:29:25 basement-music sudo[2440]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 17:29:25 basement-music sudo[2440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 17:29:25 basement-music sudo[2442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 17:29:25 basement-music sudo[2440]: pam_unix(sudo:session): session closed for user root Aug 29 17:29:25 basement-music sudo[2442]: pam_unix(sudo:session): session closed for user root Aug 29 17:29:25 basement-music volumio[1480]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.129 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:154.0) Gecko/20100101 Firefox/154.0 Engine version: 3 Transport: polling Total Clients: 6 Aug 29 17:29:26 basement-music volumio[1480]: info: New Spotify access tokenBQDL8ojiwP... Aug 29 17:29:26 basement-music volumio[1480]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetState Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 17:29:26 basement-music volumio[1480]: info: Received Get System Info Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 17:29:26 basement-music volumio[1480]: info: Discovery: Getting this device information Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetState Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetState Aug 29 17:29:26 basement-music volumio[1480]: info: Listing playlists Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 29 17:29:26 basement-music volumio[1480]: SPOTIFY: User informations: {"account_id":"8vsUgbS6fZ","country":"US","display_name":"Brian Pelletier","email":"brian.pelletier@aloe-me.net","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/lwss8i67puhgza25a49rbpyxi"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/lwss8i67puhgza25a49rbpyxi","id":"lwss8i67puhgza25a49rbpyxi","images":[],"product":"premium","type":"user","uri":"spotify:user:lwss8i67puhgza25a49rbpyxi"} Aug 29 17:29:26 basement-music volumio[1480]: info: Creating Spotify config file Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 17:29:26 basement-music volumio[1480]: info: Spotify config file written Aug 29 17:29:26 basement-music sudo[2447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 17:29:26 basement-music sudo[2447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 17:29:26 basement-music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 29 17:29:26 basement-music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 29 17:29:26 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:26 basement-music volumio[1480]: info: Connection to go-librespot Websocket closed Aug 29 17:29:26 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:26 basement-music go-librespot[2449]: go-librespot daemon starting... Aug 29 17:29:26 basement-music sudo[2447]: pam_unix(sudo:session): session closed for user root Aug 29 17:29:26 basement-music go-librespot[2450]: time="2026-08-29T17:29:26-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:29:26 basement-music go-librespot[2450]: time="2026-08-29T17:29:26-04:00" level=debug msg="app state loaded" Aug 29 17:29:26 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 28. Aug 29 17:29:26 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:29:26 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:29:26 basement-music go-librespot[2450]: time="2026-08-29T17:29:26-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:29:26 basement-music volumio[1480]: info: New Spotify access tokenBQBG7jErD1... Aug 29 17:29:26 basement-music volumio[1480]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 17:29:26 basement-music upmpdcli[2459]: Could not open config: /tmp/upmpdcli.conf Aug 29 17:29:26 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:26 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 17:29:26 basement-music volumio[1480]: SPOTIFY: User informations: {"account_id":"8vsUgbS6fZ","country":"US","display_name":"Brian Pelletier","email":"brian.pelletier@aloe-me.net","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/lwss8i67puhgza25a49rbpyxi"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/lwss8i67puhgza25a49rbpyxi","id":"lwss8i67puhgza25a49rbpyxi","images":[],"product":"premium","type":"user","uri":"spotify:user:lwss8i67puhgza25a49rbpyxi"} Aug 29 17:29:26 basement-music volumio[1480]: info: Spotify Successfully logged in Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 17:29:26 basement-music volumio[1480]: info: [1788038966987] CoreMusicLibrary::Adding element Spotify Aug 29 17:29:26 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 17:29:26 basement-music volumio[1480]: Cannot find translation for source Pandora Radio Aug 29 17:29:26 basement-music volumio[1480]: Cannot find translation for source Spotify Aug 29 17:29:27 basement-music go-librespot[2450]: time="2026-08-29T17:29:27-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:29:27 basement-music go-librespot[2450]: time="2026-08-29T17:29:27-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:29:27 basement-music go-librespot[2450]: time="2026-08-29T17:29:27-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:29:27 basement-music go-librespot[2450]: time="2026-08-29T17:29:27-04:00" level=info msg="zeroconf server listening on port 34173" Aug 29 17:29:27 basement-music go-librespot[2450]: time="2026-08-29T17:29:27-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:29:27 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:27 basement-music volumio[1480]: info: [1788038967311] ControllerPandora::removeTrack Aug 29 17:29:27 basement-music volumio[1480]: info: [1788038967311] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=5338491045908617602 at queue index: -1 Aug 29 17:29:27 basement-music go-librespot[2450]: time="2026-08-29T17:29:27-04:00" level=debug msg="obtained new client token: AAH5oOlmqH8WQFT4QHqtn4e6a8uTxNfTg4StdvVUbFfhZ6tHN4Qa76PR2ftsd4rsbAol2fikK1PfZEyUrLQE8SaAUZ4XpepFA9HqL7gQI5Tcq5oRdVIo8kfvyuEdV1vgKbQOH/Gk36eCL82uwwl6F7HxSNZ2/maM394qQQI9G9JughHXzKGYZQX3f2/0aGtFzmc2XreLZIyAWlSwjsS0jOLqsQMfutFbc5Q+U/jDHir+qToHUmqZvos=" Aug 29 17:29:27 basement-music go-librespot[2450]: time="2026-08-29T17:29:27-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:29:27 basement-music go-librespot[2450]: time="2026-08-29T17:29:27-04:00" level=debug msg="completed keyexchange" Aug 29 17:29:27 basement-music go-librespot[2450]: time="2026-08-29T17:29:27-04:00" level=debug msg="completed challenge" Aug 29 17:29:27 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 29 17:29:27 basement-music go-librespot[2450]: time="2026-08-29T17:29:27-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:29:27 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 17:29:27 basement-music volumio[1480]: info: Received Get System Info Aug 29 17:29:27 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 17:29:27 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 17:29:27 basement-music volumio[1480]: info: Discovery: Getting this device information Aug 29 17:29:27 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetState Aug 29 17:29:27 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 17:29:28 basement-music go-librespot[2450]: time="2026-08-29T17:29:28-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:29:28 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:28 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:29:28 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 17:29:28 basement-music volumio[1480]: info: Received Get System Info Aug 29 17:29:28 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 17:29:28 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 17:29:28 basement-music volumio[1480]: info: Discovery: Getting this device information Aug 29 17:29:28 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetState Aug 29 17:29:28 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 17:29:29 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:29 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:29 basement-music volumio[1480]: info: go-librespot daemon successfully initialized Aug 29 17:29:31 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 17:29:31 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:31 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:31 basement-music go-librespot[2475]: go-librespot daemon starting... Aug 29 17:29:31 basement-music go-librespot[2476]: time="2026-08-29T17:29:31-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:29:31 basement-music go-librespot[2476]: time="2026-08-29T17:29:31-04:00" level=debug msg="app state loaded" Aug 29 17:29:31 basement-music go-librespot[2476]: time="2026-08-29T17:29:31-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:29:31 basement-music go-librespot[2476]: time="2026-08-29T17:29:31-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:29:31 basement-music go-librespot[2476]: time="2026-08-29T17:29:31-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:29:31 basement-music go-librespot[2476]: time="2026-08-29T17:29:31-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:29:31 basement-music go-librespot[2476]: time="2026-08-29T17:29:31-04:00" level=info msg="zeroconf server listening on port 39921" Aug 29 17:29:31 basement-music go-librespot[2476]: time="2026-08-29T17:29:31-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:29:32 basement-music go-librespot[2476]: time="2026-08-29T17:29:32-04:00" level=debug msg="obtained new client token: AAEsyHlxm3mn0S/ZOdK5SkwKSoquZFiSbBB/4tOMSxo4Mp53zzByfg2XL/CqByte9F98pNYNzofPI6Br+KzFSRmJI/8UDky3gH4UFogUSE7DRD+4VpqsSPtJCGHimBWUdCykHzvx1jn7SEv+E9qpwW27wvBkXXM4Tlc0vHMgKUMVeeBEVKjIp4Q7kkPzURTqSUt7wf3OOwS60BIJ0ozxToSePK3aPX3UOAL/rYm8/uuCMJh+Jw==" Aug 29 17:29:32 basement-music go-librespot[2476]: time="2026-08-29T17:29:32-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:29:32 basement-music go-librespot[2476]: time="2026-08-29T17:29:32-04:00" level=debug msg="completed keyexchange" Aug 29 17:29:32 basement-music go-librespot[2476]: time="2026-08-29T17:29:32-04:00" level=debug msg="completed challenge" Aug 29 17:29:32 basement-music go-librespot[2476]: time="2026-08-29T17:29:32-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:29:32 basement-music go-librespot[2476]: time="2026-08-29T17:29:32-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:29:32 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:32 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:29:32 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:32 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:32 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:32 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:32 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetState Aug 29 17:29:34 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetQueue Aug 29 17:29:34 basement-music volumio[1480]: info: CoreStateMachine::getQueue Aug 29 17:29:34 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:35 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:35 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:35 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 17:29:35 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:35 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:35 basement-music go-librespot[2485]: go-librespot daemon starting... Aug 29 17:29:35 basement-music go-librespot[2486]: time="2026-08-29T17:29:35-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:29:35 basement-music go-librespot[2486]: time="2026-08-29T17:29:35-04:00" level=debug msg="app state loaded" Aug 29 17:29:35 basement-music go-librespot[2486]: time="2026-08-29T17:29:35-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:29:35 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 17:29:36 basement-music go-librespot[2486]: time="2026-08-29T17:29:36-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 17:29:36 basement-music go-librespot[2486]: time="2026-08-29T17:29:36-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 17:29:36 basement-music go-librespot[2486]: time="2026-08-29T17:29:36-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 17:29:36 basement-music go-librespot[2486]: time="2026-08-29T17:29:36-04:00" level=info msg="zeroconf server listening on port 34927" Aug 29 17:29:36 basement-music go-librespot[2486]: time="2026-08-29T17:29:36-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:29:36 basement-music go-librespot[2486]: time="2026-08-29T17:29:36-04:00" level=debug msg="obtained new client token: AAFmchSXuA5tes9QMnao6qPtCI/3QwyrvYyGQB3pSH6KTirl5URAGvclyFmWa46nGiTQz1lGyPGUsWp6a5qvYt1jFwyMxRcKXpHBpmqel5gUl8VUr4T6l63FFMtNQbiEZma6Y2sry5AlaaWwd8Hshq1iNnsH3DYX9h8NIk0r/7Z81ETL/lCSjG+T/ke/zTt48OBmJN70uosIiDvYME4TY1+SiHzIualeI3sAiFCkssDJ5belrkmVkao=" Aug 29 17:29:36 basement-music go-librespot[2486]: time="2026-08-29T17:29:36-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:29:36 basement-music go-librespot[2486]: time="2026-08-29T17:29:36-04:00" level=debug msg="completed keyexchange" Aug 29 17:29:36 basement-music go-librespot[2486]: time="2026-08-29T17:29:36-04:00" level=debug msg="completed challenge" Aug 29 17:29:36 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 29 17:29:36 basement-music volumio[1480]: info: In handleBrowseUri, curUri=spotify Aug 29 17:29:36 basement-music go-librespot[2486]: time="2026-08-29T17:29:36-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:29:36 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:36 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:36 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:36 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:37 basement-music go-librespot[2486]: time="2026-08-29T17:29:37-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:29:37 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:37 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:29:37 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:37 basement-music volumio[1480]: info: [1788038977311] ControllerPandora::removeTrack Aug 29 17:29:37 basement-music volumio[1480]: info: [1788038977311] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=8979009458702193333 at queue index: -1 Aug 29 17:29:38 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:38 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:40 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 29 17:29:40 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:40 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:40 basement-music go-librespot[2509]: go-librespot daemon starting... Aug 29 17:29:40 basement-music go-librespot[2510]: time="2026-08-29T17:29:40-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:29:40 basement-music go-librespot[2510]: time="2026-08-29T17:29:40-04:00" level=debug msg="app state loaded" Aug 29 17:29:40 basement-music go-librespot[2510]: time="2026-08-29T17:29:40-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:29:40 basement-music go-librespot[2510]: time="2026-08-29T17:29:40-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:29:40 basement-music go-librespot[2510]: time="2026-08-29T17:29:40-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:29:40 basement-music go-librespot[2510]: time="2026-08-29T17:29:40-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:29:40 basement-music go-librespot[2510]: time="2026-08-29T17:29:40-04:00" level=info msg="zeroconf server listening on port 45415" Aug 29 17:29:40 basement-music go-librespot[2510]: time="2026-08-29T17:29:40-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:29:41 basement-music go-librespot[2510]: time="2026-08-29T17:29:41-04:00" level=debug msg="obtained new client token: AAGffHdv63EkhdWoXt9rVZ3W4NLppt/IRmq8KEzTbk/LD8amlf5J0F/JD7dCTHgGUxFCV49xjlfkjxJVgZsZX+XeOnVGNh6ocrAKq4tkbLVbcfPOBa/UoCafDXOks/rWmStBt9iG0rncs2/AYB/0n/pS+GqH8zriB7Pwsz6NzFD53afzzRulJpnB66iy4oEjKgdbMWgzY8695kmGFz5oNzljtycyRt1rr1Rypj90b29RUKDA195/5j8=" Aug 29 17:29:41 basement-music go-librespot[2510]: time="2026-08-29T17:29:41-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:29:41 basement-music go-librespot[2510]: time="2026-08-29T17:29:41-04:00" level=debug msg="completed keyexchange" Aug 29 17:29:41 basement-music go-librespot[2510]: time="2026-08-29T17:29:41-04:00" level=debug msg="completed challenge" Aug 29 17:29:41 basement-music go-librespot[2510]: time="2026-08-29T17:29:41-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:29:41 basement-music go-librespot[2510]: time="2026-08-29T17:29:41-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:29:41 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:41 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:29:41 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:41 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:41 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 29. Aug 29 17:29:41 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:29:41 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:29:42 basement-music upmpdcli[2519]: Could not open config: /tmp/upmpdcli.conf Aug 29 17:29:42 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:42 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 17:29:43 basement-music volumio[1480]: Searching plugin music_service/spop Aug 29 17:29:43 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: spop , search Aug 29 17:29:44 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 17:29:44 basement-music volumio[1480]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 29 17:29:44 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 29 17:29:44 basement-music volumio[1480]: info: Received Get System Version Aug 29 17:29:44 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 17:29:44 basement-music volumio[1480]: info: Received Get System Info Aug 29 17:29:44 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 17:29:44 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 17:29:44 basement-music volumio[1480]: info: Discovery: Getting this device information Aug 29 17:29:44 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetState Aug 29 17:29:44 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 17:29:44 basement-music volumio[1480]: info: All search sources collected, pushing search results Aug 29 17:29:44 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:44 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:44 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 29 17:29:44 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:44 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:44 basement-music go-librespot[2520]: go-librespot daemon starting... Aug 29 17:29:44 basement-music go-librespot[2521]: time="2026-08-29T17:29:44-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:29:44 basement-music go-librespot[2521]: time="2026-08-29T17:29:44-04:00" level=debug msg="app state loaded" Aug 29 17:29:44 basement-music go-librespot[2521]: time="2026-08-29T17:29:44-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=info msg="zeroconf server listening on port 34051" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=debug msg="obtained new client token: AAFf+h+VNvB7omSJQRRe7gD1AGkhWyhmqgiV8HEnIIj5CvdoLAARMATLoz939lAkqcbRBB0+a82ftATkdEok5ygrb1+WhL4af0K9k09bEeo6h5gUIzBdvndJVmI7HfDK9M2DUTvUN0vLhKAkAFT3OEfQyrHODFLKNox98RZiu00GfmjQu/H696nTCc1hYakh8RLd4iwoHsHQptPIVrudUqFqj6uR7/ESacfBZTg+UE3PSeVY/UQD7+c=" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=debug msg="completed keyexchange" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=debug msg="completed challenge" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:29:45 basement-music go-librespot[2521]: time="2026-08-29T17:29:45-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:29:45 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:45 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:29:46 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 29 17:29:46 basement-music volumio[1480]: info: In handleBrowseUri, curUri=spotify:artist:6ZLTlhejhndI4Rh53vYhrY Aug 29 17:29:47 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:47 basement-music volumio[1480]: info: [1788038987311] ControllerPandora::removeTrack Aug 29 17:29:47 basement-music volumio[1480]: info: [1788038987311] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=3761019631141428252 at queue index: 10 Aug 29 17:29:47 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:47 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:48 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:48 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:48 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:48 basement-music volumio[1480]: info: No valid Plugin REST Endpoint Aug 29 17:29:49 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 29 17:29:49 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:49 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:49 basement-music go-librespot[2544]: go-librespot daemon starting... Aug 29 17:29:49 basement-music go-librespot[2545]: time="2026-08-29T17:29:49-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:29:49 basement-music go-librespot[2545]: time="2026-08-29T17:29:49-04:00" level=debug msg="app state loaded" Aug 29 17:29:49 basement-music go-librespot[2545]: time="2026-08-29T17:29:49-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:29:49 basement-music go-librespot[2545]: time="2026-08-29T17:29:49-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:29:49 basement-music go-librespot[2545]: time="2026-08-29T17:29:49-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:29:49 basement-music go-librespot[2545]: time="2026-08-29T17:29:49-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:29:49 basement-music go-librespot[2545]: time="2026-08-29T17:29:49-04:00" level=info msg="zeroconf server listening on port 45939" Aug 29 17:29:49 basement-music go-librespot[2545]: time="2026-08-29T17:29:49-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:29:50 basement-music go-librespot[2545]: time="2026-08-29T17:29:50-04:00" level=debug msg="obtained new client token: AAEIVBs98RTsXygsbAqmVuKz+K2YOydoOOwuMHhDcd919mpPwpfOA/bSmzO+/T15WHmVNTlnAMKYag5wu0zoCpjcZfdIldJVKbcyyi6i/AmdO7gNuZqwe5yZHmU9Keb5WwuyseeWk2onOrB5sYVaxnPRzx0F7t/0n5Xl3SI14KbNokDF7w921Uc6U7qNYN6u95JlawmVOC5/HoZK4oZowZZ4AyOVNradUHe/m2SzhtNu05hnu/CDcjc=" Aug 29 17:29:50 basement-music go-librespot[2545]: time="2026-08-29T17:29:50-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:29:50 basement-music go-librespot[2545]: time="2026-08-29T17:29:50-04:00" level=debug msg="completed keyexchange" Aug 29 17:29:50 basement-music go-librespot[2545]: time="2026-08-29T17:29:50-04:00" level=debug msg="completed challenge" Aug 29 17:29:50 basement-music go-librespot[2545]: time="2026-08-29T17:29:50-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:29:50 basement-music go-librespot[2545]: time="2026-08-29T17:29:50-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:29:50 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:50 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:29:50 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:50 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:50 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::ClearQueue Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::stop Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::updateTrackBlock Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrackBlock Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::stPlaybackTimer Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrack 10 Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::serviceStop Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrack 10 Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::serviceStop Aug 29 17:29:50 basement-music volumio[1480]: info: [1788038990714] ControllerPandora::stop Aug 29 17:29:50 basement-music volumio[1480]: info: ControllerMpd::stop Aug 29 17:29:50 basement-music volumio[1480]: verbose: ControllerMpd::sendMpdCommand stop Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::clearPlayQueue Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::saveQueue Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushQueue Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::addQueueItems Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::addQueueItems Aug 29 17:29:50 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:50 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 17:29:50 basement-music volumio[1480]: info: Using cached record of: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 17:29:50 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 17:29:50 basement-music volumio[1480]: info: Using cached record of: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushQueue Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::saveQueue Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::updateTrackBlock Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrackBlock Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPlay Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::play index 1 Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::addQueueItems Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::addQueueItems Aug 29 17:29:50 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:50 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 17:29:50 basement-music volumio[1480]: info: Using cached record of: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 17:29:50 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 17:29:50 basement-music volumio[1480]: info: Using cached record of: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 17:29:50 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 17:29:50 basement-music volumio[1480]: info: Using cached record of: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 17:29:50 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 17:29:50 basement-music volumio[1480]: info: Using cached record of: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 17:29:50 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 17:29:50 basement-music volumio[1480]: info: Using cached record of: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 17:29:50 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 17:29:50 basement-music volumio[1480]: info: Using cached record of: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 17:29:50 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 17:29:50 basement-music volumio[1480]: info: Using cached record of: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 17:29:50 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 17:29:50 basement-music volumio[1480]: info: Using cached record of: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::stop Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushQueue Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::saveQueue Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::play index undefined Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::updateTrackBlock Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrackBlock Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::startPlaybackTimer Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:50 basement-music volumio[1480]: info: [1788038990775] ControllerSpotify::clearAddPlayTrack Aug 29 17:29:50 basement-music volumio[1480]: info: Sending Spotify command with payload to local API: /player/play Aug 29 17:29:50 basement-music volumio[1480]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Aug 29 17:29:50 basement-music volumio[1480]: info: Aug 29 17:29:50 basement-music volumio[1480]: ---------------------------- MPD announces state update: player Aug 29 17:29:50 basement-music volumio[1480]: info: sendMpdCommand stop took 84 milliseconds Aug 29 17:29:50 basement-music volumio[1480]: info: ControllerMpd::getState Aug 29 17:29:50 basement-music volumio[1480]: verbose: ControllerMpd::sendMpdCommand status Aug 29 17:29:50 basement-music volumio[1480]: info: ControllerMpd::clear Aug 29 17:29:50 basement-music volumio[1480]: verbose: ControllerMpd::sendMpdCommand clear Aug 29 17:29:50 basement-music volumio[1480]: info: Aug 29 17:29:50 basement-music volumio[1480]: ---------------------------- MPD announces state update: player Aug 29 17:29:50 basement-music volumio[1480]: info: ControllerMpd::getState Aug 29 17:29:50 basement-music volumio[1480]: verbose: ControllerMpd::sendMpdCommand status Aug 29 17:29:50 basement-music volumio[1480]: info: Aug 29 17:29:50 basement-music volumio[1480]: ---------------------------- MPD announces state update: player Aug 29 17:29:50 basement-music volumio[1480]: info: ControllerMpd::getState Aug 29 17:29:50 basement-music volumio[1480]: verbose: ControllerMpd::sendMpdCommand status Aug 29 17:29:50 basement-music volumio[1480]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:50 basement-music volumio[1480]: info: Aug 29 17:29:50 basement-music volumio[1480]: ---------------------------- MPD announces system playlist update Aug 29 17:29:50 basement-music volumio[1480]: info: Ignoring MPD Status Update Aug 29 17:29:50 basement-music volumio[1480]: info: sendMpdCommand status took 15 milliseconds Aug 29 17:29:50 basement-music volumio[1480]: info: sendMpdCommand clear took 15 milliseconds Aug 29 17:29:50 basement-music volumio[1480]: info: sendMpdCommand status took 10 milliseconds Aug 29 17:29:50 basement-music volumio[1480]: info: sendMpdCommand status took 9 milliseconds Aug 29 17:29:50 basement-music volumio[1480]: verbose: ControllerMpd::parseState Aug 29 17:29:50 basement-music volumio[1480]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 17:29:50 basement-music volumio[1480]: info: [1788038990817] ControllerPandora::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::servicePushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushState Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:50 basement-music volumio[1480]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received pandora Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 29 17:29:50 basement-music volumio[1480]: verbose: ControllerMpd::parseState Aug 29 17:29:50 basement-music volumio[1480]: verbose: ControllerMpd::parseState Aug 29 17:29:50 basement-music volumio[1480]: info: ControllerMpd::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::servicePushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushState Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:50 basement-music volumio[1480]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 29 17:29:50 basement-music volumio[1480]: verbose: CURRENT POSITION 1 Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::syncState stateService stop Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::syncState currentStatus stop Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushState Aug 29 17:29:50 basement-music volumio[1480]: info: No code Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushState Aug 29 17:29:50 basement-music volumio[1480]: info: ControllerMpd::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::servicePushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushState Aug 29 17:29:50 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:50 basement-music volumio[1480]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 29 17:29:50 basement-music volumio[1480]: verbose: CURRENT POSITION 1 Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::syncState stateService stop Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::syncState currentStatus stop Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushState Aug 29 17:29:50 basement-music volumio[1480]: info: No code Aug 29 17:29:50 basement-music volumio[1480]: info: CoreStateMachine::pushState Aug 29 17:29:50 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushState Aug 29 17:29:50 basement-music volumio[1480]: info: ------------------------------ 148ms Aug 29 17:29:50 basement-music volumio[1480]: info: ------------------------------ 147ms Aug 29 17:29:50 basement-music volumio[1480]: info: Aug 29 17:29:50 basement-music volumio[1480]: ---------------------------- MPD announces system playlist update Aug 29 17:29:50 basement-music volumio[1480]: info: Ignoring MPD Status Update Aug 29 17:29:50 basement-music volumio[1480]: info: Aug 29 17:29:50 basement-music volumio[1480]: ---------------------------- MPD announces system playlist update Aug 29 17:29:50 basement-music volumio[1480]: info: Ignoring MPD Status Update Aug 29 17:29:50 basement-music volumio[1480]: error: updateQueue error: null Aug 29 17:29:50 basement-music volumio[1480]: error: updateQueue error: null Aug 29 17:29:50 basement-music volumio[1480]: error: updateQueue error: null Aug 29 17:29:50 basement-music volumio[1480]: info: ------------------------------ 153ms Aug 29 17:29:50 basement-music volumio[1480]: info: sendMpdCommand playlistinfo took 151 milliseconds Aug 29 17:29:50 basement-music volumio[1480]: info: ------------------------------ 12ms Aug 29 17:29:50 basement-music volumio[1480]: info: ------------------------------ 8ms Aug 29 17:29:50 basement-music volumio[1480]: verbose: ControllerMpd::parseTrackInfo Aug 29 17:29:50 basement-music volumio[1480]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 29 17:29:50 basement-music volumio[1480]: info: ------------------------------ 173ms Aug 29 17:29:50 basement-music volumio[1480]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Aug 29 17:29:50 basement-music volumio[1480]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Aug 29 17:29:50 basement-music volumio[1480]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Aug 29 17:29:50 basement-music volumio[1480]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Aug 29 17:29:51 basement-music volumio[1480]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Aug 29 17:29:51 basement-music volumio[1480]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Aug 29 17:29:51 basement-music volumio[1480]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Aug 29 17:29:53 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:53 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:53 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 29 17:29:53 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:53 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:53 basement-music go-librespot[2554]: go-librespot daemon starting... Aug 29 17:29:53 basement-music go-librespot[2555]: time="2026-08-29T17:29:53-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:29:53 basement-music go-librespot[2555]: time="2026-08-29T17:29:53-04:00" level=debug msg="app state loaded" Aug 29 17:29:53 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:53 basement-music volumio[1480]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::ClearQueue Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::stop Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:53 basement-music volumio[1480]: info: CorePlayQueue::clearPlayQueue Aug 29 17:29:53 basement-music volumio[1480]: info: CorePlayQueue::saveQueue Aug 29 17:29:53 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushQueue Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::addQueueItems Aug 29 17:29:53 basement-music volumio[1480]: info: CorePlayQueue::addQueueItems Aug 29 17:29:53 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:53 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 17:29:53 basement-music volumio[1480]: info: Using cached record of: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 17:29:53 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 17:29:53 basement-music volumio[1480]: info: Using cached record of: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 17:29:53 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushQueue Aug 29 17:29:53 basement-music volumio[1480]: info: CorePlayQueue::saveQueue Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::updateTrackBlock Aug 29 17:29:53 basement-music volumio[1480]: info: CorePlayQueue::getTrackBlock Aug 29 17:29:53 basement-music volumio[1480]: info: CoreCommandRouter::volumioPlay Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::play index 1 Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::addQueueItems Aug 29 17:29:53 basement-music volumio[1480]: info: CorePlayQueue::addQueueItems Aug 29 17:29:53 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:53 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 17:29:53 basement-music volumio[1480]: info: Using cached record of: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 17:29:53 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 17:29:53 basement-music volumio[1480]: info: Using cached record of: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 17:29:53 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 17:29:53 basement-music volumio[1480]: info: Using cached record of: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 17:29:53 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 17:29:53 basement-music volumio[1480]: info: Using cached record of: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 17:29:53 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 17:29:53 basement-music volumio[1480]: info: Using cached record of: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 17:29:53 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 17:29:53 basement-music volumio[1480]: info: Using cached record of: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 17:29:53 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 17:29:53 basement-music volumio[1480]: info: Using cached record of: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 17:29:53 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 17:29:53 basement-music volumio[1480]: info: Using cached record of: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::stop Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:53 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushQueue Aug 29 17:29:53 basement-music go-librespot[2555]: time="2026-08-29T17:29:53-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:29:53 basement-music volumio[1480]: info: CorePlayQueue::saveQueue Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::play index undefined Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::updateTrackBlock Aug 29 17:29:53 basement-music volumio[1480]: info: CorePlayQueue::getTrackBlock Aug 29 17:29:53 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:53 basement-music volumio[1480]: info: CoreStateMachine::startPlaybackTimer Aug 29 17:29:53 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:53 basement-music volumio[1480]: info: [1788038993872] ControllerSpotify::clearAddPlayTrack Aug 29 17:29:53 basement-music volumio[1480]: info: Sending Spotify command with payload to local API: /player/play Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=info msg="zeroconf server listening on port 32959" Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=debug msg="obtained new client token: AAHbJrz/IX0pds5NBeXCTekVh9dzONVQZnufFwp/r4RSYK3Hs0DDiDDD5h9weQH7+EG2he83FtuOErrcdX0yZZBRmVrF7gV//jl4l2x9ZqWR9/RFp+fCkljBG99GFAQrjgMFufqV62XDRxq1Bx4PXrh6h7iZvvNyHw3i8DZwYGANOkCVx3R09jeDgSbh15Wfv98G9+kEoGR1DQfSD576FWlSoAs4Lv6gT177+KrUOuiSjatZu2VnAZU=" Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=debug msg="completed keyexchange" Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=debug msg="completed challenge" Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:29:54 basement-music go-librespot[2555]: time="2026-08-29T17:29:54-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:29:55 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:55 basement-music volumio[1480]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Aug 29 17:29:55 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:29:56 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:56 basement-music volumio[1480]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::ClearQueue Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::stop Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:56 basement-music volumio[1480]: info: CorePlayQueue::clearPlayQueue Aug 29 17:29:56 basement-music volumio[1480]: info: CorePlayQueue::saveQueue Aug 29 17:29:56 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushQueue Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::addQueueItems Aug 29 17:29:56 basement-music volumio[1480]: info: CorePlayQueue::addQueueItems Aug 29 17:29:56 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:56 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 17:29:56 basement-music volumio[1480]: info: Using cached record of: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 17:29:56 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 17:29:56 basement-music volumio[1480]: info: Using cached record of: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 17:29:56 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushQueue Aug 29 17:29:56 basement-music volumio[1480]: info: CorePlayQueue::saveQueue Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::updateTrackBlock Aug 29 17:29:56 basement-music volumio[1480]: info: CorePlayQueue::getTrackBlock Aug 29 17:29:56 basement-music volumio[1480]: info: CoreCommandRouter::volumioPlay Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::play index 1 Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::addQueueItems Aug 29 17:29:56 basement-music volumio[1480]: info: CorePlayQueue::addQueueItems Aug 29 17:29:56 basement-music volumio[1480]: info: Preload queue cleared Aug 29 17:29:56 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 17:29:56 basement-music volumio[1480]: info: Using cached record of: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 17:29:56 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 17:29:56 basement-music volumio[1480]: info: Using cached record of: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 17:29:56 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 17:29:56 basement-music volumio[1480]: info: Using cached record of: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 17:29:56 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 17:29:56 basement-music volumio[1480]: info: Using cached record of: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 17:29:56 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 17:29:56 basement-music volumio[1480]: info: Using cached record of: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 17:29:56 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 17:29:56 basement-music volumio[1480]: info: Using cached record of: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 17:29:56 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 17:29:56 basement-music volumio[1480]: info: Using cached record of: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 17:29:56 basement-music volumio[1480]: info: Adding Item to queue: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 17:29:56 basement-music volumio[1480]: info: Using cached record of: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::stop Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:56 basement-music volumio[1480]: info: CoreCommandRouter::volumioPushQueue Aug 29 17:29:56 basement-music volumio[1480]: info: CorePlayQueue::saveQueue Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::play index undefined Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::updateTrackBlock Aug 29 17:29:56 basement-music volumio[1480]: info: CorePlayQueue::getTrackBlock Aug 29 17:29:56 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:56 basement-music volumio[1480]: info: CoreStateMachine::startPlaybackTimer Aug 29 17:29:56 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:56 basement-music volumio[1480]: info: [1788038996253] ControllerSpotify::clearAddPlayTrack Aug 29 17:29:56 basement-music volumio[1480]: info: Sending Spotify command with payload to local API: /player/play Aug 29 17:29:56 basement-music volumio[1480]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:56 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:56 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:29:57 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 30. Aug 29 17:29:57 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:29:57 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:29:57 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:29:57 basement-music volumio[1480]: info: [1788038997311] ControllerPandora::removeTrack Aug 29 17:29:57 basement-music volumio[1480]: info: [1788038997312] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=6232139454696690650 at queue index: -1 Aug 29 17:29:57 basement-music upmpdcli[2565]: Could not open config: /tmp/upmpdcli.conf Aug 29 17:29:57 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:57 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 17:29:58 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 29 17:29:58 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:58 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:29:58 basement-music go-librespot[2580]: go-librespot daemon starting... Aug 29 17:29:58 basement-music go-librespot[2581]: time="2026-08-29T17:29:58-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:29:58 basement-music go-librespot[2581]: time="2026-08-29T17:29:58-04:00" level=debug msg="app state loaded" Aug 29 17:29:58 basement-music go-librespot[2581]: time="2026-08-29T17:29:58-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:29:58 basement-music go-librespot[2581]: time="2026-08-29T17:29:58-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:29:58 basement-music go-librespot[2581]: time="2026-08-29T17:29:58-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:29:58 basement-music go-librespot[2581]: time="2026-08-29T17:29:58-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:29:58 basement-music go-librespot[2581]: time="2026-08-29T17:29:58-04:00" level=info msg="zeroconf server listening on port 33073" Aug 29 17:29:58 basement-music go-librespot[2581]: time="2026-08-29T17:29:58-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:29:59 basement-music go-librespot[2581]: time="2026-08-29T17:29:59-04:00" level=debug msg="obtained new client token: AAFEEOzDO56KXiWKRhSd3LarwJGO/NijwnJxtrIWTR1voalsHRLqd4Uk8fEsApglwP82Y9LWoL1VX/gNxG+0kIWBd46WBpOSL451PqEbuWqmz/inH8WESmS7WAFRQYaRVpehH183HbUdNyKRIBZN1S7PMwUwpVI5guhh2Wj/5+uRKWFc17mHjlVpF+JZsRw/SOMLiOktY7UVXCSF8nsyrDCJrmm77czsFhr8qpnHfE9vVBZ8UHRZiJc=" Aug 29 17:29:59 basement-music go-librespot[2581]: time="2026-08-29T17:29:59-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:29:59 basement-music go-librespot[2581]: time="2026-08-29T17:29:59-04:00" level=debug msg="completed keyexchange" Aug 29 17:29:59 basement-music go-librespot[2581]: time="2026-08-29T17:29:59-04:00" level=debug msg="completed challenge" Aug 29 17:29:59 basement-music go-librespot[2581]: time="2026-08-29T17:29:59-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:29:59 basement-music go-librespot[2581]: time="2026-08-29T17:29:59-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:29:59 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:29:59 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:29:59 basement-music volumio[1480]: info: CoreCommandRouter::volumioGetState Aug 29 17:29:59 basement-music volumio[1480]: info: CorePlayQueue::getTrack 1 Aug 29 17:29:59 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:29:59 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:02 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:02 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 29 17:30:02 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:02 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:02 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:02 basement-music go-librespot[2591]: go-librespot daemon starting... Aug 29 17:30:02 basement-music go-librespot[2592]: time="2026-08-29T17:30:02-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:02 basement-music go-librespot[2592]: time="2026-08-29T17:30:02-04:00" level=debug msg="app state loaded" Aug 29 17:30:02 basement-music go-librespot[2592]: time="2026-08-29T17:30:02-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:03 basement-music go-librespot[2592]: time="2026-08-29T17:30:03-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 17:30:03 basement-music go-librespot[2592]: time="2026-08-29T17:30:03-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 17:30:03 basement-music go-librespot[2592]: time="2026-08-29T17:30:03-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 17:30:03 basement-music go-librespot[2592]: time="2026-08-29T17:30:03-04:00" level=info msg="zeroconf server listening on port 36745" Aug 29 17:30:03 basement-music go-librespot[2592]: time="2026-08-29T17:30:03-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:03 basement-music go-librespot[2592]: time="2026-08-29T17:30:03-04:00" level=debug msg="obtained new client token: AAFoCx5g0LEEwtiW4iYwat1hCnL4xjNR+Qm0X0Ufj33vP4vjOzSMYe2YiA7h+1+Q8V7fFggV00Ir6rD8JF2euhsnK9+VYzx1aAGtSse58xr1hyVfon0/BxQ7UyZ8lQxVBr4/A3dFxnLyZPsCQ30SLLhbUnvp1Hh1OSKxKI8OIt8ej9Gj11HLWTTGSMcdA3odz1emvTH2+BojxUmuWy4S2LtL/faErjILfl+Tooxv1ZnsHaBLatehByM=" Aug 29 17:30:03 basement-music go-librespot[2592]: time="2026-08-29T17:30:03-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:30:03 basement-music go-librespot[2592]: time="2026-08-29T17:30:03-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:03 basement-music go-librespot[2592]: time="2026-08-29T17:30:03-04:00" level=debug msg="completed challenge" Aug 29 17:30:03 basement-music go-librespot[2592]: time="2026-08-29T17:30:03-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:04 basement-music go-librespot[2592]: time="2026-08-29T17:30:04-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:04 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:04 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:05 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:05 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:07 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 29 17:30:07 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:07 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:07 basement-music go-librespot[2601]: go-librespot daemon starting... Aug 29 17:30:07 basement-music go-librespot[2602]: time="2026-08-29T17:30:07-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:07 basement-music go-librespot[2602]: time="2026-08-29T17:30:07-04:00" level=debug msg="app state loaded" Aug 29 17:30:07 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:30:07 basement-music volumio[1480]: info: [1788039007311] ControllerPandora::removeTrack Aug 29 17:30:07 basement-music volumio[1480]: info: [1788039007311] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=7620185592383389884 at queue index: -1 Aug 29 17:30:07 basement-music go-librespot[2602]: time="2026-08-29T17:30:07-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:07 basement-music go-librespot[2602]: time="2026-08-29T17:30:07-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:30:07 basement-music go-librespot[2602]: time="2026-08-29T17:30:07-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:30:07 basement-music go-librespot[2602]: time="2026-08-29T17:30:07-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:30:07 basement-music go-librespot[2602]: time="2026-08-29T17:30:07-04:00" level=info msg="zeroconf server listening on port 46149" Aug 29 17:30:07 basement-music go-librespot[2602]: time="2026-08-29T17:30:07-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:08 basement-music go-librespot[2602]: time="2026-08-29T17:30:08-04:00" level=debug msg="obtained new client token: AAFAbZCTsd6/qW1gTHNtwoGf47if9lDLYhcTubAP5/83KtxAK9/GPti7lIQKhLW/uHm3iKVhPSEz/buuZGBjcQ3OOSO9Ld4jPT1J4w2SbcsvC7eGrv6bPz3w8yfmoJ6jrOwUBx5H61pQ/oR3r9JoudQ4fg0xpCerLlsNFhIHCZEWitzrkBAIC6nmyNRRp9jLdMT9WGcazIGI8WL8ki4s/E7tStlXDnEq3bKULA8eQ8bCX1LsbL/fW5E=" Aug 29 17:30:08 basement-music go-librespot[2602]: time="2026-08-29T17:30:08-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:30:08 basement-music go-librespot[2602]: time="2026-08-29T17:30:08-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:08 basement-music go-librespot[2602]: time="2026-08-29T17:30:08-04:00" level=debug msg="completed challenge" Aug 29 17:30:08 basement-music go-librespot[2602]: time="2026-08-29T17:30:08-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:08 basement-music go-librespot[2602]: time="2026-08-29T17:30:08-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:08 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:08 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:08 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:08 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:11 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 29 17:30:11 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:11 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:11 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:11 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:11 basement-music go-librespot[2625]: go-librespot daemon starting... Aug 29 17:30:11 basement-music go-librespot[2626]: time="2026-08-29T17:30:11-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:11 basement-music go-librespot[2626]: time="2026-08-29T17:30:11-04:00" level=debug msg="app state loaded" Aug 29 17:30:11 basement-music go-librespot[2626]: time="2026-08-29T17:30:11-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:12 basement-music go-librespot[2626]: time="2026-08-29T17:30:12-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:30:12 basement-music go-librespot[2626]: time="2026-08-29T17:30:12-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:30:12 basement-music go-librespot[2626]: time="2026-08-29T17:30:12-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:30:12 basement-music go-librespot[2626]: time="2026-08-29T17:30:12-04:00" level=info msg="zeroconf server listening on port 35885" Aug 29 17:30:12 basement-music go-librespot[2626]: time="2026-08-29T17:30:12-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:12 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 31. Aug 29 17:30:12 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:30:12 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:30:12 basement-music go-librespot[2626]: time="2026-08-29T17:30:12-04:00" level=debug msg="obtained new client token: AAFW8TQHZ2WslqALWW8+LLpGwDcEyKSddlTQBvmXnoOOJ9Br7sYSpxjuBBqQbVS170daj3fAp/pEnhmnqOeiSZb/djJ/r+Sr0urNCfWFjayoB2Tc44sKgz7zbSytZiDxOZkvQ6cvA+PTzebsfWoxGdKTBXDivY6SWd+aOw7/CScwuk01tzkhzb25VbT52qwRRTxu20ShCS2Dxz/c6OR3/nsmB2arBUfZ6d2lmlTsAv/l+iRZGI/cRXU=" Aug 29 17:30:12 basement-music upmpdcli[2635]: Could not open config: /tmp/upmpdcli.conf Aug 29 17:30:12 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:12 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 17:30:12 basement-music go-librespot[2626]: time="2026-08-29T17:30:12-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:30:12 basement-music go-librespot[2626]: time="2026-08-29T17:30:12-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:12 basement-music go-librespot[2626]: time="2026-08-29T17:30:12-04:00" level=debug msg="completed challenge" Aug 29 17:30:12 basement-music go-librespot[2626]: time="2026-08-29T17:30:12-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:13 basement-music go-librespot[2626]: time="2026-08-29T17:30:13-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:13 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:13 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:14 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:14 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:16 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 29 17:30:16 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:16 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:16 basement-music go-librespot[2637]: go-librespot daemon starting... Aug 29 17:30:16 basement-music go-librespot[2638]: time="2026-08-29T17:30:16-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:16 basement-music go-librespot[2638]: time="2026-08-29T17:30:16-04:00" level=debug msg="app state loaded" Aug 29 17:30:16 basement-music go-librespot[2638]: time="2026-08-29T17:30:16-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:16 basement-music go-librespot[2638]: time="2026-08-29T17:30:16-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:30:16 basement-music go-librespot[2638]: time="2026-08-29T17:30:16-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:30:16 basement-music go-librespot[2638]: time="2026-08-29T17:30:16-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:30:16 basement-music go-librespot[2638]: time="2026-08-29T17:30:16-04:00" level=info msg="zeroconf server listening on port 45963" Aug 29 17:30:16 basement-music go-librespot[2638]: time="2026-08-29T17:30:16-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:17 basement-music go-librespot[2638]: time="2026-08-29T17:30:17-04:00" level=debug msg="obtained new client token: AAHhq9sW9Kee91Glf4GnMhzO2HqcHPyjRzi32wHp4evWCb/rP+uIjhMkxthD/xNqvFzYJs16WnpsS4G6cyNjOzDGb9RzKfVqtqJ/O8/wx3hu9ZvfTHO/zeL7WpIXEwpmKUEYyy+UOUZRrriFzGgCLyfwideOh3QnOERlGdcjD9m2G9jf1P6tV6A2afujl/yKjJihkVPItHBOo3jaVJy1zYzPsidiiTNQkkV88HzYTLtKQ3GrvS7944k=" Aug 29 17:30:17 basement-music go-librespot[2638]: time="2026-08-29T17:30:17-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:30:17 basement-music go-librespot[2638]: time="2026-08-29T17:30:17-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:17 basement-music go-librespot[2638]: time="2026-08-29T17:30:17-04:00" level=debug msg="completed challenge" Aug 29 17:30:17 basement-music go-librespot[2638]: time="2026-08-29T17:30:17-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:17 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:30:17 basement-music volumio[1480]: info: [1788039017312] ControllerPandora::removeTrack Aug 29 17:30:17 basement-music volumio[1480]: info: [1788039017312] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=3971586774713721489 at queue index: -1 Aug 29 17:30:17 basement-music go-librespot[2638]: time="2026-08-29T17:30:17-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:17 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:17 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:17 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:17 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:20 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 29 17:30:20 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:20 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:20 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:20 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:20 basement-music go-librespot[2662]: go-librespot daemon starting... Aug 29 17:30:20 basement-music go-librespot[2663]: time="2026-08-29T17:30:20-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:20 basement-music go-librespot[2663]: time="2026-08-29T17:30:20-04:00" level=debug msg="app state loaded" Aug 29 17:30:20 basement-music go-librespot[2663]: time="2026-08-29T17:30:20-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=info msg="zeroconf server listening on port 44153" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=debug msg="obtained new client token: AAHWYJymu54q/g5VgcUaxq/fL1fzDJ37P2Lr9vKigoUPG1VmjSe6gmviBA22MVJ2tiOfcr5qOyiMcCzBLUxGjkE3vtiP9d5AFcs0EDRCowMzmbLg7EvcmGglUMqED84AK5IS55Qw/Bz6cTvceJUr5gwcyfI5NIZwdJp4GiTxSNSunA1prOb2TD5ihGunpTT5eeZf4a9uArrq3LQBmjJrVKvOiZYba5DEBksO8WbZGk1KjVM6LwaO+Mk=" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=debug msg="completed challenge" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:21 basement-music go-librespot[2663]: time="2026-08-29T17:30:21-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:22 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:22 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:23 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:23 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:25 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 29 17:30:25 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:25 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:25 basement-music go-librespot[2672]: go-librespot daemon starting... Aug 29 17:30:25 basement-music go-librespot[2673]: time="2026-08-29T17:30:25-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:25 basement-music go-librespot[2673]: time="2026-08-29T17:30:25-04:00" level=debug msg="app state loaded" Aug 29 17:30:25 basement-music go-librespot[2673]: time="2026-08-29T17:30:25-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:25 basement-music go-librespot[2673]: time="2026-08-29T17:30:25-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:30:25 basement-music go-librespot[2673]: time="2026-08-29T17:30:25-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:30:25 basement-music go-librespot[2673]: time="2026-08-29T17:30:25-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:30:25 basement-music go-librespot[2673]: time="2026-08-29T17:30:25-04:00" level=info msg="zeroconf server listening on port 40431" Aug 29 17:30:25 basement-music go-librespot[2673]: time="2026-08-29T17:30:25-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:26 basement-music go-librespot[2673]: time="2026-08-29T17:30:26-04:00" level=debug msg="obtained new client token: AAE6pU4IVsI+7bIpi8U1M6+gshtl2l3bY4YPNyY+NA/dqFFy6pNiCh5z2X3oI9R5BVBZAQpHukbUlesUmVusJLrygWXntzetYFE8OKQOlmXjTYlWxJTfWj4BPEAlEx8Fa6+QgIUJp+ZTRGGKIYJcq/z4GentL0uf7eccAETH/R7OTorEhf8HOjNlM9UDimhA9vcxJBL/gv+0Ci2puAwzBTajmYpob3y4YJRQb/fFFe6dwmifYDsJXLE=" Aug 29 17:30:26 basement-music go-librespot[2673]: time="2026-08-29T17:30:26-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:30:26 basement-music go-librespot[2673]: time="2026-08-29T17:30:26-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:26 basement-music go-librespot[2673]: time="2026-08-29T17:30:26-04:00" level=debug msg="completed challenge" Aug 29 17:30:26 basement-music go-librespot[2673]: time="2026-08-29T17:30:26-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:26 basement-music go-librespot[2673]: time="2026-08-29T17:30:26-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:26 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:26 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:26 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:26 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:27 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:30:27 basement-music volumio[1480]: info: [1788039027312] ControllerPandora::removeTrack Aug 29 17:30:27 basement-music volumio[1480]: info: [1788039027312] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=2214611531760828690 at queue index: -1 Aug 29 17:30:27 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 32. Aug 29 17:30:27 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:30:27 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:30:27 basement-music upmpdcli[2682]: Could not open config: /tmp/upmpdcli.conf Aug 29 17:30:27 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:27 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 17:30:29 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 29 17:30:29 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:29 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:29 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:29 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:29 basement-music go-librespot[2698]: go-librespot daemon starting... Aug 29 17:30:29 basement-music go-librespot[2699]: time="2026-08-29T17:30:29-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:29 basement-music go-librespot[2699]: time="2026-08-29T17:30:29-04:00" level=debug msg="app state loaded" Aug 29 17:30:29 basement-music go-librespot[2699]: time="2026-08-29T17:30:29-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=info msg="zeroconf server listening on port 38283" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=debug msg="obtained new client token: AAHFtJfxBS+a9rwOCLFfy4RS8w3bDDIJmGhwzX0f4cKz/VCuboevqEdPcMzj4oDvrjnvn6DNCPtE/ex87HrDWkdHhMLbntSRFjx5aKRatFdpaSYBIpUNDSfZ0JUUU6fb2+1s3QFxmAjv8f2tmtlG+hlDapRxPIfichtD0MrRFSmILWTkjX2bR/OuF7HWhmeGSb5AJwQkTMv4IDrRY5mpXJYvd8+9mGHzhow4eqG6pnAJ0PmwGBzmFcY=" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=debug msg="connected to ap-gue1.spotify.com:443" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=debug msg="completed challenge" Aug 29 17:30:30 basement-music go-librespot[2699]: time="2026-08-29T17:30:30-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:31 basement-music go-librespot[2699]: time="2026-08-29T17:30:31-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:31 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:31 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:32 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:32 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:34 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 29 17:30:34 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:34 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:34 basement-music go-librespot[2708]: go-librespot daemon starting... Aug 29 17:30:34 basement-music go-librespot[2709]: time="2026-08-29T17:30:34-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:34 basement-music go-librespot[2709]: time="2026-08-29T17:30:34-04:00" level=debug msg="app state loaded" Aug 29 17:30:34 basement-music go-librespot[2709]: time="2026-08-29T17:30:34-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:34 basement-music go-librespot[2709]: time="2026-08-29T17:30:34-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:30:34 basement-music go-librespot[2709]: time="2026-08-29T17:30:34-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:30:34 basement-music go-librespot[2709]: time="2026-08-29T17:30:34-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:30:34 basement-music go-librespot[2709]: time="2026-08-29T17:30:34-04:00" level=info msg="zeroconf server listening on port 38179" Aug 29 17:30:34 basement-music go-librespot[2709]: time="2026-08-29T17:30:34-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:35 basement-music go-librespot[2709]: time="2026-08-29T17:30:35-04:00" level=debug msg="obtained new client token: AAEV1EzmA2a0IH5JCtMZaTrPjvSjgyG1qP/oTcKSEc+iqt4kLRVLx2ohnT5HVVXJ3NuhsvYn17MqRqmIyTo7k7zKJ/fRw7sbH6H5gncq0hRal7GmCWBdIMDxzSCn8bJGoczLReKlUOCgnRKbK/pCK0tMPtRMPFs9By+q/IFnAPYnVtiC2Jt17Utxr9ToSV/vnHuSgbLJSC1qpnvKoLszOFEpISHeH53E/mmHSM/Adp83iPtydtkuQeg=" Aug 29 17:30:35 basement-music go-librespot[2709]: time="2026-08-29T17:30:35-04:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Aug 29 17:30:35 basement-music go-librespot[2709]: time="2026-08-29T17:30:35-04:00" level=debug msg="connected to ap-gue1.spotify.com:443" Aug 29 17:30:35 basement-music go-librespot[2709]: time="2026-08-29T17:30:35-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:35 basement-music go-librespot[2709]: time="2026-08-29T17:30:35-04:00" level=debug msg="completed challenge" Aug 29 17:30:35 basement-music go-librespot[2709]: time="2026-08-29T17:30:35-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:35 basement-music go-librespot[2709]: time="2026-08-29T17:30:35-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:35 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:35 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:35 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:35 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:37 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:30:37 basement-music volumio[1480]: info: [1788039037312] ControllerPandora::removeTrack Aug 29 17:30:37 basement-music volumio[1480]: info: [1788039037312] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=8166104659098739394 at queue index: -1 Aug 29 17:30:38 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 29 17:30:38 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:38 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:38 basement-music go-librespot[2733]: go-librespot daemon starting... Aug 29 17:30:38 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:38 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:38 basement-music go-librespot[2734]: time="2026-08-29T17:30:38-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:38 basement-music go-librespot[2734]: time="2026-08-29T17:30:38-04:00" level=debug msg="app state loaded" Aug 29 17:30:38 basement-music go-librespot[2734]: time="2026-08-29T17:30:38-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=info msg="zeroconf server listening on port 40297" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=debug msg="obtained new client token: AAEw7+F/o22s8nk0JuOAPWeJalnd9BDlMsZSffSTXsRxEWPok6UJl19/f6Ba8lPRyUIgLI0bqpFJTQtQAn0cwJmy0aM8WjTqSzPEm+mDT1XvC8t1rJzbrxTdDMzMDUQjm9gEkTMQiS0/k6Ox0u7M5cW5EIkvpYkHqtfQ8Tgq7w+L8phJtqukRRObyKQ/pgksco4P/2yQZ4jaWzYXbAPLoQ8eBm8EOq68+/QupxI3J6mxObqd/3s1D+k=" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=debug msg="completed challenge" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:39 basement-music go-librespot[2734]: time="2026-08-29T17:30:39-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:39 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:39 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:41 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:41 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:42 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 33. Aug 29 17:30:42 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:30:43 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 17:30:43 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 29 17:30:43 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:43 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:43 basement-music go-librespot[2744]: go-librespot daemon starting... Aug 29 17:30:43 basement-music upmpdcli[2743]: Could not open config: /tmp/upmpdcli.conf Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=debug msg="app state loaded" Aug 29 17:30:43 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:43 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=info msg="zeroconf server listening on port 41819" Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=debug msg="obtained new client token: AAHC1itEsypDBWOYjwKXWzKr7jiFM9YL7ZQOMx8hfmk4Kgd6I4BAxj2dzxEFu6OZD/ggCYxExC2EsTvasAPdFs7mbSkylXHZ5ZCVPqZ2cfctmh0JpNFf4ri84UPLtlGEYEx+qm6M1giG4BG6/X/xPvQqyHGT4zqaq/4dxFf1957IATNEl4By1Siz/HslTHoAW2VZxfkTpv4UZKqC+PxP4Ucq5N0x8j65CGCyYpb20g68GZPJhnRx9D0=" Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:43 basement-music go-librespot[2745]: time="2026-08-29T17:30:43-04:00" level=debug msg="completed challenge" Aug 29 17:30:44 basement-music go-librespot[2745]: time="2026-08-29T17:30:44-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:44 basement-music go-librespot[2745]: time="2026-08-29T17:30:44-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:44 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:44 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:44 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:44 basement-music volumio[1480]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:47 basement-music volumio[1480]: info: CorePlayQueue::getQueue Aug 29 17:30:47 basement-music volumio[1480]: info: [1788039047311] ControllerPandora::removeTrack Aug 29 17:30:47 basement-music volumio[1480]: info: [1788039047311] [Pandora] removeTrack: Not removing track with uri: /pandora/stationToken=202462973774539151trackId=5152376645463155362 at queue index: -1 Aug 29 17:30:47 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 29 17:30:47 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:47 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:47 basement-music go-librespot[2754]: go-librespot daemon starting... Aug 29 17:30:47 basement-music go-librespot[2755]: time="2026-08-29T17:30:47-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:47 basement-music go-librespot[2755]: time="2026-08-29T17:30:47-04:00" level=debug msg="app state loaded" Aug 29 17:30:47 basement-music go-librespot[2755]: time="2026-08-29T17:30:47-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:47 basement-music volumio[1480]: info: Initializing connection to go-librespot Websocket Aug 29 17:30:47 basement-music go-librespot[2755]: time="2026-08-29T17:30:47-04:00" level=debug msg="new websocket client" Aug 29 17:30:47 basement-music volumio[1480]: info: Connection to go-librespot Websocket established Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=info msg="zeroconf server listening on port 35225" Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=debug msg="obtained new client token: AAEakhvz/xviCOXfKjcWyu6oc4MY/OS4f8VKhjKPRhsnRFd9rI6FRBiOxF5ZE5/wSXEtH/64lFMl+2WkEcfBL8BdHvPEm+ioapDOJ7juKY89fnRD2dYSYegRu2rPweWb3dY2pltN+90Z0RTTcBqZR49CTyUAcMJ2um0pLMWweLEboILCj63dd0hbxrrxm9g0j5iD49OnMJJu0dByk8o+i5xxE7oNSFa08vczF3J2DuIGg3m4P3PV" Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=debug msg="completed keyexchange" Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=debug msg="completed challenge" Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 17:30:48 basement-music go-librespot[2755]: time="2026-08-29T17:30:48-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:30:48 basement-music volumio[1480]: info: Connection to go-librespot Websocket closed Aug 29 17:30:48 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:30:48 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:30:50 basement-music volumio[1480]: info: Getting Spotify volume Aug 29 17:30:50 basement-music volumio[1480]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 17:30:50 basement-music volumio[1480]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:30:50 basement-music volumio[1480]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 29 17:30:50 basement-music volumio[1480]: errno: -111, Aug 29 17:30:50 basement-music volumio[1480]: code: 'ECONNREFUSED', Aug 29 17:30:50 basement-music volumio[1480]: syscall: 'connect', Aug 29 17:30:50 basement-music volumio[1480]: address: '127.0.0.1', Aug 29 17:30:50 basement-music volumio[1480]: port: 9879, Aug 29 17:30:50 basement-music volumio[1480]: response: undefined Aug 29 17:30:50 basement-music volumio[1480]: } Aug 29 17:30:50 basement-music volumio[1480]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 17:30:51 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 29 17:30:51 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:51 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:30:51 basement-music go-librespot[2790]: go-librespot daemon starting... Aug 29 17:30:51 basement-music go-librespot[2791]: time="2026-08-29T17:30:51-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:30:51 basement-music go-librespot[2791]: time="2026-08-29T17:30:51-04:00" level=debug msg="app state loaded" Aug 29 17:30:52 basement-music go-librespot[2791]: time="2026-08-29T17:30:52-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:30:52 basement-music sudo[2801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 17:29' Aug 29 17:30:52 basement-music sudo[2801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 17:30:52 basement-music go-librespot[2791]: time="2026-08-29T17:30:52-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 17:30:52 basement-music go-librespot[2791]: time="2026-08-29T17:30:52-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 17:30:52 basement-music go-librespot[2791]: time="2026-08-29T17:30:52-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 17:30:52 basement-music go-librespot[2791]: time="2026-08-29T17:30:52-04:00" level=info msg="zeroconf server listening on port 42611" Aug 29 17:30:52 basement-music go-librespot[2791]: time="2026-08-29T17:30:52-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" 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"