Feb 18 03:43:00 volumio volumio[8444]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 03:43:00 volumio volumio[8444]: info: Discovery: Found device Volumio Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::volumioGetState Feb 18 03:43:00 volumio volumio[8444]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:00 volumio volumio[8444]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 03:43:00 volumio volumio[8444]: info: Discovery: Found device Volumio Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::volumioGetState Feb 18 03:43:00 volumio volumio[8444]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:00 volumio volumio[8444]: info: MPD Permissions set Feb 18 03:43:00 volumio volumio[8444]: info: MPD Permissions set Feb 18 03:43:00 volumio volumio[8444]: info: Upmpdcli Daemon Started Feb 18 03:43:00 volumio volumio[8444]: info: Spotify config file written Feb 18 03:43:00 volumio volumio[8444]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio sudo[8680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 03:43:00 volumio sudo[8680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:00 volumio go-librespot[8689]: go-librespot daemon starting... Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:00 volumio volumio[8444]: info: No need to fix Spotify hosts Feb 18 03:43:00 volumio sudo[8680]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:00 volumio go-librespot[8693]: time="2026-02-18T03:43:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:00 volumio go-librespot[8693]: time="2026-02-18T03:43:00+07:00" level=debug msg="app state loaded" Feb 18 03:43:00 volumio go-librespot[8693]: time="2026-02-18T03:43:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:01 volumio go-librespot[8693]: time="2026-02-18T03:43:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 03:43:01 volumio go-librespot[8693]: time="2026-02-18T03:43:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 03:43:01 volumio go-librespot[8693]: time="2026-02-18T03:43:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 03:43:01 volumio go-librespot[8693]: time="2026-02-18T03:43:01+07:00" level=info msg="zeroconf server listening on port 41117" Feb 18 03:43:01 volumio go-librespot[8693]: time="2026-02-18T03:43:01+07:00" level=debug msg="obtained new client token: AABcXyjygRQgfxkeDTinnf3sd3ltJSnwrj9wBwNQl7b3US+WwaWEGzIP0EDIiv6nvWdwUPnsmp16xKCLEkXoMYfbOGBwyFx7mjD6YH7ckBHuNcgM9eebQiMpVzC7kus5PWjqGfJ8a4cRXgjUd7UhKj9Ly+NzJbo/D30NOWMSmC19fetOOI0DNT3aXL8NoyPP1rU2Y1+2eYnMGPpgM5lvW1d0ceZHkuwutdVIS81I8fU4i5EBBOp33kt3+A==" Feb 18 03:43:01 volumio go-librespot[8693]: time="2026-02-18T03:43:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:01 volumio go-librespot[8693]: time="2026-02-18T03:43:01+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:01 volumio go-librespot[8693]: time="2026-02-18T03:43:01+07:00" level=debug msg="completed challenge" Feb 18 03:43:02 volumio go-librespot[8693]: time="2026-02-18T03:43:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:02 volumio volumio[8444]: info: Volumio called home Feb 18 03:43:02 volumio volumio[8444]: info: Starting Shairport Sync Feb 18 03:43:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:02 volumio volumio[8444]: info: Starting Shairport Sync Feb 18 03:43:02 volumio volumio[8444]: info: Starting Shairport Sync Feb 18 03:43:02 volumio sudo[8723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 03:43:02 volumio sudo[8721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 03:43:02 volumio sudo[8721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:02 volumio sudo[8723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:02 volumio sudo[8726]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 03:43:02 volumio sudo[8726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 03:43:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 03:43:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 03:43:02 volumio systemd[1]: shairport-sync.service: Consumed 2.266s CPU time. Feb 18 03:43:02 volumio volumio[8444]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 03:43:02 volumio volumio[8444]: SPOTIFY: BQDZKedjUMLOrwRYxgILHTWtUANNQL3uzYm6pO5ZU6OW2ERlgl3zySotPgduaWWHz1Po_woff311a1HjLbmuxKLX7SIUgiz5tJ5C4jk7Yeh1VDmQh1F52zESS-lu05pHfHUuNca6oxjvzTMOBJ-TBpysziTcol35d1D7F5q3SO0CCzIxDB8uNPCs7-EHfS70Vk6m7dWlCyUVAMtYtVkURJ1vCNA3Eu9sCucdeaw9LetxlXxmcWfYJeOVW-SIS2oeE_VgeiWILRUsAiSZs5XcZ-nIqjZ_yrNgheTJo4aPoMBx1hngeQKAVZSp Feb 18 03:43:02 volumio volumio[8444]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 03:43:02 volumio volumio[8444]: info: New Spotify access token = BQDZKedjUMLOrwRYxgILHTWtUANNQL3uzYm6pO5ZU6OW2ERlgl3zySotPgduaWWHz1Po_woff311a1HjLbmuxKLX7SIUgiz5tJ5C4jk7Yeh1VDmQh1F52zESS-lu05pHfHUuNca6oxjvzTMOBJ-TBpysziTcol35d1D7F5q3SO0CCzIxDB8uNPCs7-EHfS70Vk6m7dWlCyUVAMtYtVkURJ1vCNA3Eu9sCucdeaw9LetxlXxmcWfYJeOVW-SIS2oeE_VgeiWILRUsAiSZs5XcZ-nIqjZ_yrNgheTJo4aPoMBx1hngeQKAVZSp Feb 18 03:43:02 volumio volumio[8444]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 03:43:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 03:43:02 volumio sudo[8721]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:02 volumio sudo[8723]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:02 volumio sudo[8726]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:02 volumio volumio[8444]: info: CoreCommandRouter::volumioGetState Feb 18 03:43:02 volumio volumio[8444]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:02 volumio volumio[8444]: info: Shairport-Sync Started Feb 18 03:43:02 volumio volumio[8444]: Error adding Membership: Error: addMembership EINVAL Feb 18 03:43:02 volumio volumio[8444]: info: Shairport-Sync Started Feb 18 03:43:02 volumio volumio[8444]: info: Shairport-Sync Started Feb 18 03:43:02 volumio volumio[8444]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 03:43:02 volumio volumio[8444]: info: Spotify Successfully logged in Feb 18 03:43:02 volumio volumio[8444]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:43:02 volumio volumio[8444]: info: [1771360982996] CoreMusicLibrary::Adding element Spotify Feb 18 03:43:02 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:43:03 volumio volumio[8444]: Cannot find translation for source YouTube Music Feb 18 03:43:03 volumio volumio[8444]: Cannot find translation for source Spotify Feb 18 03:43:03 volumio volumio[8444]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 03:43:03 volumio volumio[8444]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 03:43:03 volumio volumio[8444]: info: VolumeController:: Volume=100 Mute =false Feb 18 03:43:03 volumio volumio[8444]: info: CoreCommandRouter::volumioGetState Feb 18 03:43:03 volumio volumio[8444]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:03 volumio volumio[8444]: info: CoreStateMachine::pushState Feb 18 03:43:03 volumio volumio[8444]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:03 volumio volumio[8444]: info: CoreCommandRouter::volumioPushState Feb 18 03:43:05 volumio volumio[8444]: info: go-librespot daemon successfully initialized Feb 18 03:43:05 volumio mpd[8672]: 2026-02-18T03:43:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 03:43:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 03:43:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 03:43:05 volumio sudo[8624]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:05 volumio sudo[8635]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:05 volumio go-librespot[8764]: go-librespot daemon starting... Feb 18 03:43:05 volumio go-librespot[8767]: time="2026-02-18T03:43:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:05 volumio go-librespot[8767]: time="2026-02-18T03:43:05+07:00" level=debug msg="app state loaded" Feb 18 03:43:05 volumio go-librespot[8767]: time="2026-02-18T03:43:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:05 volumio volumio[8444]: error: MPD error: The expression evaluated to a falsy value: Feb 18 03:43:05 volumio volumio[8444]: assert.ok(self.idling) Feb 18 03:43:05 volumio volumio[8444]: error: The expression evaluated to a falsy value: Feb 18 03:43:05 volumio volumio[8444]: assert.ok(self.idling) Feb 18 03:43:05 volumio volumio[8444]: info: MPD running with PID8672 Feb 18 03:43:05 volumio volumio[8444]: ,establishing connection Feb 18 03:43:05 volumio volumio[8444]: error: updateQueue error: null Feb 18 03:43:05 volumio volumio[8444]: info: Completed starting Core Plugins Feb 18 03:43:05 volumio volumio[8444]: info: ------------------------------------------- Feb 18 03:43:05 volumio volumio[8444]: info: ----- MyVolumio plugins startup ---- Feb 18 03:43:05 volumio volumio[8444]: info: ------------------------------------------- Feb 18 03:43:05 volumio volumio[8444]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 03:43:05 volumio volumio[8444]: error: updateQueue error: null Feb 18 03:43:05 volumio go-librespot[8767]: time="2026-02-18T03:43:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:43:05 volumio go-librespot[8767]: time="2026-02-18T03:43:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:43:05 volumio go-librespot[8767]: time="2026-02-18T03:43:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:43:05 volumio go-librespot[8767]: time="2026-02-18T03:43:05+07:00" level=info msg="zeroconf server listening on port 32833" Feb 18 03:43:06 volumio go-librespot[8767]: time="2026-02-18T03:43:06+07:00" level=debug msg="obtained new client token: AAC3aqXdLKZzYJWwc8etcp1Wslct0kLKHhqSloegG2q3F0wNyE5h0q7rB7dHGhN19N1P4BIUo7U5pcfsSoP2g5cbNFmTQq1owZPg4Ph92wNGFCH2Er86EPcOqW11lR3ql2nYOZMk6NTFAU5B5b4P2zxQ7uoUHeJmMeGv2dcLsZndCQSoxIlZoAXZm0K/s3mq7bOP1wV14q6vmcwxZSFrAB2r/FzHR4Mcg3UL6t08yQaeTF2O9bkCCvI=" Feb 18 03:43:06 volumio go-librespot[8767]: time="2026-02-18T03:43:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:06 volumio go-librespot[8767]: time="2026-02-18T03:43:06+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:06 volumio go-librespot[8767]: time="2026-02-18T03:43:06+07:00" level=debug msg="completed challenge" Feb 18 03:43:06 volumio go-librespot[8767]: time="2026-02-18T03:43:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:08 volumio volumio[8444]: info: Initializing connection to go-librespot Websocket Feb 18 03:43:08 volumio volumio[8444]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:43:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 03:43:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:09 volumio go-librespot[8775]: go-librespot daemon starting... Feb 18 03:43:09 volumio go-librespot[8776]: time="2026-02-18T03:43:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:09 volumio go-librespot[8776]: time="2026-02-18T03:43:09+07:00" level=debug msg="app state loaded" Feb 18 03:43:09 volumio go-librespot[8776]: time="2026-02-18T03:43:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:10 volumio go-librespot[8776]: time="2026-02-18T03:43:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:43:10 volumio go-librespot[8776]: time="2026-02-18T03:43:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:43:10 volumio go-librespot[8776]: time="2026-02-18T03:43:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:43:10 volumio go-librespot[8776]: time="2026-02-18T03:43:10+07:00" level=info msg="zeroconf server listening on port 37305" Feb 18 03:43:10 volumio volumio[8444]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 03:43:10 volumio go-librespot[8776]: time="2026-02-18T03:43:10+07:00" level=debug msg="obtained new client token: AAC1GelZWK6QqYRbjfD+TcQYPY73GTglZjMBAPKEq1QecnzeIFL2Ux4Jo7mUvOopPFFxUwtYf/DurR2ChRfYQkqvsjfVrIoj7NC3y+Zu+5ygMlONGniTPY+sqniAf924xP2TlPb2ODP2ysNIJhFH5p0c0b/rwm6+UW17n6l7RWXMLHjCKq4tPis0nX14MQE3G0j+LTM2EBJ7FFOsyfOvEhCJnuHWhSeFnbdZjSoVAU979rI8jiI4e/Rugw==" Feb 18 03:43:10 volumio go-librespot[8776]: time="2026-02-18T03:43:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:10 volumio go-librespot[8776]: time="2026-02-18T03:43:10+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:10 volumio go-librespot[8776]: time="2026-02-18T03:43:10+07:00" level=debug msg="completed challenge" Feb 18 03:43:10 volumio go-librespot[8776]: time="2026-02-18T03:43:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:11 volumio volumio[8444]: info: Initializing connection to go-librespot Websocket Feb 18 03:43:11 volumio volumio[8444]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:43:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 03:43:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:13 volumio go-librespot[8783]: go-librespot daemon starting... Feb 18 03:43:13 volumio go-librespot[8784]: time="2026-02-18T03:43:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:13 volumio go-librespot[8784]: time="2026-02-18T03:43:13+07:00" level=debug msg="app state loaded" Feb 18 03:43:13 volumio go-librespot[8784]: time="2026-02-18T03:43:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:14 volumio volumio[8444]: info: Initializing connection to go-librespot Websocket Feb 18 03:43:14 volumio go-librespot[8784]: time="2026-02-18T03:43:14+07:00" level=debug msg="new websocket client" Feb 18 03:43:14 volumio volumio[8444]: info: Connection to go-librespot Websocket established Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 03:43:14 volumio volumio[8444]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 03:43:14 volumio volumio[8444]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 03:43:14 volumio volumio[8444]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 03:43:14 volumio volumio[8444]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 03:43:14 volumio volumio[8444]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 03:43:14 volumio volumio[8444]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 03:43:14 volumio volumio[8444]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 03:43:14 volumio volumio[8444]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 03:43:14 volumio go-librespot[8784]: time="2026-02-18T03:43:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:43:14 volumio go-librespot[8784]: time="2026-02-18T03:43:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:43:14 volumio go-librespot[8784]: time="2026-02-18T03:43:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:43:14 volumio go-librespot[8784]: time="2026-02-18T03:43:14+07:00" level=info msg="zeroconf server listening on port 43095" Feb 18 03:43:14 volumio go-librespot[8784]: time="2026-02-18T03:43:14+07:00" level=debug msg="obtained new client token: AAAMijMgPi9G6yq0K0E2TkZSyfO2Oa+6UDTFLmR282MixGF4YSViRDHsFKalFMkqEynNSLh9c1z7aDPFT43mvNPWvwZZCrMlYbUIKFXG/93iWL/g1xb6q1kOptI3wRW1WlwhuHRbtSolts3CI91cqcqlwtSLkhZWPl0Ptz81xkAPZXLmsfgamYF6w7aiGmzYUHixpuTXVpUDseE4NKbEUBLd+VgKZQNwFkFBgRTrOca02iHiQnpkxGul2g==" Feb 18 03:43:14 volumio go-librespot[8784]: time="2026-02-18T03:43:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 03:43:14 volumio go-librespot[8784]: time="2026-02-18T03:43:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 03:43:14 volumio go-librespot[8784]: time="2026-02-18T03:43:14+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:14 volumio go-librespot[8784]: time="2026-02-18T03:43:14+07:00" level=debug msg="completed challenge" Feb 18 03:43:15 volumio go-librespot[8784]: time="2026-02-18T03:43:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:16 volumio volumio[8444]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 03:43:16 volumio volumio[8444]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 03:43:16 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:16 volumio volumio[8444]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:16 volumio volumio[8444]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 03:43:16 volumio volumio[8444]: info: MyVolumio login type: Token Feb 18 03:43:16 volumio volumio[8444]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 03:43:16 volumio volumio[8444]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 03:43:17 volumio volumio[8444]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 03:43:17 volumio volumio[8444]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 03:43:17 volumio volumio[8444]: info: Streaming services startup Feb 18 03:43:17 volumio volumio[8444]: info: Starting Streaming Daemon Feb 18 03:43:18 volumio sudo[8806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 03:43:18 volumio sudo[8806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:18 volumio volumio[8444]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 03:43:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 18 03:43:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:18 volumio sudo[8806]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:18 volumio volumio[8444]: info: Getting Spotify volume Feb 18 03:43:18 volumio go-librespot[8812]: go-librespot daemon starting... Feb 18 03:43:18 volumio volumio[8444]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 03:43:18 volumio go-librespot[8813]: time="2026-02-18T03:43:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:18 volumio go-librespot[8813]: time="2026-02-18T03:43:18+07:00" level=debug msg="app state loaded" Feb 18 03:43:18 volumio volumio[8444]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:43:18 volumio volumio[8444]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 03:43:18 volumio volumio[8444]: errno: -111, Feb 18 03:43:18 volumio volumio[8444]: code: 'ECONNREFUSED', Feb 18 03:43:18 volumio volumio[8444]: syscall: 'connect', Feb 18 03:43:18 volumio volumio[8444]: address: '127.0.0.1', Feb 18 03:43:18 volumio volumio[8444]: port: 9879, Feb 18 03:43:18 volumio volumio[8444]: response: undefined Feb 18 03:43:18 volumio volumio[8444]: } Feb 18 03:43:18 volumio volumio[8444]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 03:43:18 volumio go-librespot[8813]: time="2026-02-18T03:43:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:18 volumio go-librespot[8813]: time="2026-02-18T03:43:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 03:43:18 volumio go-librespot[8813]: time="2026-02-18T03:43:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 03:43:18 volumio go-librespot[8813]: time="2026-02-18T03:43:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 03:43:18 volumio go-librespot[8813]: time="2026-02-18T03:43:18+07:00" level=info msg="zeroconf server listening on port 41487" Feb 18 03:43:18 volumio go-librespot[8813]: time="2026-02-18T03:43:18+07:00" level=debug msg="obtained new client token: AAC7IRWp+P5uVn8/Tt4XpjSvdU/mPck2CV3Rp6UXSKCY4VqxihbqPTNutyKPNYagi5prP0UQ3XcnbVZvoCPcBLrAba5n6bGW2zfduO3JGQERREXI2MFPTIoRe+whOILAHu2nG/3fB3EYSvZBZZmf60qCynAcOgewwoXgBjbP2p307dbtiNdLa571r+Ve7P0A0zfSd0Ghwhu43PIprLhAZLXWoxBi2HownHkhwsZ4iIhi3eNWao64NNUthQ==" Feb 18 03:43:19 volumio go-librespot[8813]: time="2026-02-18T03:43:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:19 volumio go-librespot[8813]: time="2026-02-18T03:43:19+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:19 volumio go-librespot[8813]: time="2026-02-18T03:43:19+07:00" level=debug msg="completed challenge" Feb 18 03:43:19 volumio go-librespot[8813]: time="2026-02-18T03:43:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:19 volumio sudo[8835]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 03:42' Feb 18 03:43:19 volumio sudo[8835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:19 volumio sudo[8835]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:20 volumio volumio-remote-updater[25144]: [2026-02-18 03:43:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 03:43:20 volumio volumio-remote-updater[25144]: [2026-02-18 03:43:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 03:43:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 03:43:20 volumio systemd[1]: volumio.service: Consumed 54.902s CPU time. Feb 18 03:43:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 03:43:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 03:43:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21313. Feb 18 03:43:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 03:43:20 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 03:43:20 volumio systemd[1]: volumio.service: Consumed 54.902s CPU time. Feb 18 03:43:20 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 03:43:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 03:43:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 18 03:43:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:22 volumio go-librespot[8870]: go-librespot daemon starting... Feb 18 03:43:22 volumio go-librespot[8871]: time="2026-02-18T03:43:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:22 volumio go-librespot[8871]: time="2026-02-18T03:43:22+07:00" level=debug msg="app state loaded" Feb 18 03:43:22 volumio go-librespot[8871]: time="2026-02-18T03:43:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:22 volumio go-librespot[8871]: time="2026-02-18T03:43:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:43:22 volumio go-librespot[8871]: time="2026-02-18T03:43:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:43:22 volumio go-librespot[8871]: time="2026-02-18T03:43:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:43:22 volumio go-librespot[8871]: time="2026-02-18T03:43:22+07:00" level=info msg="zeroconf server listening on port 37065" Feb 18 03:43:23 volumio go-librespot[8871]: time="2026-02-18T03:43:23+07:00" level=debug msg="obtained new client token: AAD7MGdddr+yyG92CP4Agls1TyMRExsZdFuU/oOW6a6v4ZKJ3Q1CBmL+XoWfXrihtjYU+raQNZo2hXQxTGAZ+2asIkaSxCkNpFv353eQMUO5mCCvU1BFxDSZPYtjfPnC7Rk2gyIGLUslcnZAtJ3ltsEZvmxUTwYCCci7wjhVGbSzyxcBT1/bZX8PGDFbfhW7TqV/BzkDX8PocLOqMm2QkIWbwRqrUEamrvpddCni+0A4rSVvkMRKCR4=" Feb 18 03:43:23 volumio go-librespot[8871]: time="2026-02-18T03:43:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:23 volumio go-librespot[8871]: time="2026-02-18T03:43:23+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:23 volumio go-librespot[8871]: time="2026-02-18T03:43:23+07:00" level=debug msg="completed challenge" Feb 18 03:43:23 volumio go-librespot[8871]: time="2026-02-18T03:43:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:23 volumio volumio[8854]: info: ------------------------------------------- Feb 18 03:43:24 volumio volumio[8854]: info: ----- Volumio3 ---- Feb 18 03:43:24 volumio volumio[8854]: info: ------------------------------------------- Feb 18 03:43:24 volumio volumio[8854]: info: ----- System startup ---- Feb 18 03:43:24 volumio volumio[8854]: info: ------------------------------------------- Feb 18 03:43:25 volumio volumio-remote-updater[25144]: [2026-02-18 03:43:25] [connect] Successful connection Feb 18 03:43:25 volumio volumio[8854]: info: MYVOLUMIO Environment detected Feb 18 03:43:25 volumio volumio[8854]: info: Plugin folders cleanup Feb 18 03:43:25 volumio volumio[8854]: info: Scanning into folder /volumio/app/plugins/ Feb 18 03:43:25 volumio volumio[8854]: info: Scanning category audio_interface Feb 18 03:43:25 volumio volumio[8854]: info: Scanning category miscellanea Feb 18 03:43:25 volumio volumio[8854]: info: Scanning category music_service Feb 18 03:43:25 volumio volumio[8854]: info: Scanning category plugins.json Feb 18 03:43:25 volumio volumio[8854]: info: Scanning category system_controller Feb 18 03:43:25 volumio volumio[8854]: info: Scanning category user_interface Feb 18 03:43:25 volumio volumio[8854]: info: Scanning into folder /data/plugins/ Feb 18 03:43:25 volumio volumio[8854]: info: Scanning category music_service Feb 18 03:43:25 volumio volumio[8854]: info: Plugin folders cleanup completed Feb 18 03:43:25 volumio volumio[8854]: info: ------------------------------------------- Feb 18 03:43:25 volumio volumio[8854]: info: ----- Core plugins startup ---- Feb 18 03:43:25 volumio volumio[8854]: info: ------------------------------------------- Feb 18 03:43:25 volumio volumio[8854]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 03:43:25 volumio volumio[8854]: info: Adding plugin upnp to MyMusic Plugins Feb 18 03:43:25 volumio volumio[8854]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 03:43:25 volumio volumio[8854]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 03:43:25 volumio volumio[8854]: info: Loading plugins from folder /data/plugins/ Feb 18 03:43:25 volumio volumio[8854]: info: Loading plugin "system"... Feb 18 03:43:25 volumio volumio[8854]: info: Loading plugin "appearance"... Feb 18 03:43:26 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 18 03:43:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 18 03:43:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:26 volumio go-librespot[8902]: go-librespot daemon starting... Feb 18 03:43:26 volumio go-librespot[8903]: time="2026-02-18T03:43:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:26 volumio go-librespot[8903]: time="2026-02-18T03:43:26+07:00" level=debug msg="app state loaded" Feb 18 03:43:26 volumio go-librespot[8903]: time="2026-02-18T03:43:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:27 volumio go-librespot[8903]: time="2026-02-18T03:43:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:43:27 volumio go-librespot[8903]: time="2026-02-18T03:43:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:43:27 volumio go-librespot[8903]: time="2026-02-18T03:43:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:43:27 volumio go-librespot[8903]: time="2026-02-18T03:43:27+07:00" level=info msg="zeroconf server listening on port 36989" Feb 18 03:43:27 volumio go-librespot[8903]: time="2026-02-18T03:43:27+07:00" level=debug msg="obtained new client token: AABQQZN3LlBBfHv4nT6ZuJn4e/a41UJqHUSSAenjkGqadJClQ7FZttyl/smdBy7G5Y66/y+ctEslbdsaIoA1isllF5t+QcsK6sLCx0XFkXP0d3Y8qu/seLq9VYP+0U3HK0pXKRk8GTV4O88V8XXDt/e4iiHGh/Q6KM0VdGr9Api2rpRnuxcUkwaPfUHs18nn1pEy3bpg3eQMhitDUafWuHc1fW57yXo6O/WraGNvufXF5Pco5PA7dX/mVw==" Feb 18 03:43:27 volumio go-librespot[8903]: time="2026-02-18T03:43:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:27 volumio volumio[8854]: info: Loading plugin "network"... Feb 18 03:43:27 volumio go-librespot[8903]: time="2026-02-18T03:43:27+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:27 volumio go-librespot[8903]: time="2026-02-18T03:43:27+07:00" level=debug msg="completed challenge" Feb 18 03:43:27 volumio volumio[8854]: info: Refreshing Cached IP Addresses Feb 18 03:43:27 volumio sudo[8915]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 03:43:27 volumio sudo[8915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:27 volumio go-librespot[8903]: time="2026-02-18T03:43:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:27 volumio sudo[8917]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 03:43:27 volumio sudo[8917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:27 volumio sudo[8917]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:27 volumio volumio[8854]: info: Loading plugin "services"... Feb 18 03:43:27 volumio volumio[8854]: info: Loading plugin "alsa_controller"... Feb 18 03:43:27 volumio sudo[8915]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:27 volumio sudo[8924]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 03:43:27 volumio sudo[8924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:27 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 03:43:27 volumio volumio[8854]: info: Loading plugin "wizard"... Feb 18 03:43:28 volumio volumio[8854]: info: Loading plugin "networkfs"... Feb 18 03:43:28 volumio volumio[8854]: info: Starting Udev Watcher for removable devices Feb 18 03:43:28 volumio volumio[8854]: info: Ignoring mount for partition: boot Feb 18 03:43:28 volumio volumio[8854]: info: Ignoring mount for partition: volumio Feb 18 03:43:28 volumio volumio[8854]: info: Ignoring mount for partition: volumio_data Feb 18 03:43:28 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 03:43:28 volumio volumio[8854]: info: Loading plugin "volumio_command_line_client"... Feb 18 03:43:28 volumio volumio[8854]: info: Loading plugin "upnp"... Feb 18 03:43:28 volumio volumio[8854]: info: [1771361008134] Starting Upmpd Daemon Feb 18 03:43:28 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 03:43:28 volumio volumio[8854]: info: Loading plugin "my_music"... Feb 18 03:43:28 volumio volumio[8854]: info: Loading plugin "mpd"... Feb 18 03:43:28 volumio volumio[8854]: info: Loading plugin "upnp_browser"... Feb 18 03:43:28 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 18 03:43:28 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 18 03:43:28 volumio systemd[1]: setdatetime-helper.service: Consumed 1.990s CPU time. Feb 18 03:43:30 volumio sudo[8924]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 18 03:43:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:30 volumio go-librespot[8957]: go-librespot daemon starting... Feb 18 03:43:30 volumio go-librespot[8958]: time="2026-02-18T03:43:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:30 volumio go-librespot[8958]: time="2026-02-18T03:43:30+07:00" level=debug msg="app state loaded" Feb 18 03:43:30 volumio go-librespot[8958]: time="2026-02-18T03:43:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:31 volumio go-librespot[8958]: time="2026-02-18T03:43:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:43:31 volumio go-librespot[8958]: time="2026-02-18T03:43:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:43:31 volumio go-librespot[8958]: time="2026-02-18T03:43:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:43:31 volumio go-librespot[8958]: time="2026-02-18T03:43:31+07:00" level=info msg="zeroconf server listening on port 45235" Feb 18 03:43:31 volumio go-librespot[8958]: time="2026-02-18T03:43:31+07:00" level=debug msg="obtained new client token: AAC2QLEdvcp8Qt3TC8ZFstOlkFjv7dpLe9Ts65KAwGCWDGXDSIIXBKn+0uYFVBf4KOHcTGfIkLSO1idS5DwKC4nJflXw/OAECcdVFVEJZMV12UHgg5IFgl7aO3J9IZFmZlYPN2y9sUnPcg5gmx6j14CgsUDzOkvujA3cAVCartkZ1NAb8Zh4uiq5N3gMwGnP3ZJFUvxfsGuU6xtMbJfFlWIhyWyK8UrGC7Vz4fOOsazkymSEczszTccpNg==" Feb 18 03:43:31 volumio go-librespot[8958]: time="2026-02-18T03:43:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:31 volumio volumio[8854]: info: Starting UPNP Browser Feb 18 03:43:31 volumio volumio[8854]: info: Loading plugin "alarm-clock"... Feb 18 03:43:31 volumio go-librespot[8958]: time="2026-02-18T03:43:31+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:31 volumio go-librespot[8958]: time="2026-02-18T03:43:31+07:00" level=debug msg="completed challenge" Feb 18 03:43:31 volumio go-librespot[8958]: time="2026-02-18T03:43:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:32 volumio volumio[8854]: info: Loading plugin "airplay_emulation"... Feb 18 03:43:32 volumio volumio[8854]: info: Starting Shairport Sync Feb 18 03:43:32 volumio volumio[8854]: info: Loading plugin "last_100"... Feb 18 03:43:32 volumio volumio[8854]: info: Loading plugin "webradio"... Feb 18 03:43:32 volumio volumio[8854]: info: Loading plugin "i2s_dacs"... Feb 18 03:43:32 volumio volumio[8854]: info: Loading plugin "volumiodiscovery"... Feb 18 03:43:32 volumio volumio[8854]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 03:43:32 volumio volumio[8854]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 03:43:32 volumio node[8854]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 03:43:32 volumio volumio[8854]: *** WARNING *** For more information see Feb 18 03:43:32 volumio volumio[8854]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 03:43:32 volumio volumio[8854]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 03:43:32 volumio volumio[8854]: *** WARNING *** For more information see Feb 18 03:43:32 volumio node[8854]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 03:43:32 volumio node[8854]: *** WARNING *** For more information see Feb 18 03:43:32 volumio node[8854]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 03:43:32 volumio node[8854]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 03:43:32 volumio node[8854]: *** WARNING *** For more information see Feb 18 03:43:32 volumio volumio[8854]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 03:43:32 volumio volumio[8854]: info: Discovery: Started advertising with name: Volumio Feb 18 03:43:32 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 03:43:32 volumio volumio[8854]: info: Loading plugin "spop"... Feb 18 03:43:34 volumio volumio[8854]: info: Loading plugin "ytcr"... Feb 18 03:43:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 18 03:43:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:35 volumio go-librespot[8967]: go-librespot daemon starting... Feb 18 03:43:35 volumio go-librespot[8968]: time="2026-02-18T03:43:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:35 volumio go-librespot[8968]: time="2026-02-18T03:43:35+07:00" level=debug msg="app state loaded" Feb 18 03:43:35 volumio go-librespot[8968]: time="2026-02-18T03:43:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:35 volumio go-librespot[8968]: time="2026-02-18T03:43:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 03:43:35 volumio go-librespot[8968]: time="2026-02-18T03:43:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 03:43:35 volumio go-librespot[8968]: time="2026-02-18T03:43:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 03:43:35 volumio go-librespot[8968]: time="2026-02-18T03:43:35+07:00" level=info msg="zeroconf server listening on port 34517" Feb 18 03:43:36 volumio go-librespot[8968]: time="2026-02-18T03:43:36+07:00" level=debug msg="obtained new client token: AAAJQVgpdBsG7XdiG4GToqAHYW2pGN/W0m4nacd/dgNBvuXc58cIakfl584+H4+dRUDunuse+DcHLe6w5QgXY3jzgqnnOSMjxUk98Dk6+/CYyFAKcDPdpCJH/OhVFICwSU1IrK//uf+9U7CtfcrN2GK4Tfo1d1Fj+vgRiPWuk1w1xkDFJY5HLUnkio6pVqaggh427bCEyngR60d1JtDG/RPkh2ek6BFfYX+XJjMBP9tMHbu+mpuwM//oXQ==" Feb 18 03:43:36 volumio go-librespot[8968]: time="2026-02-18T03:43:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:36 volumio go-librespot[8968]: time="2026-02-18T03:43:36+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:36 volumio go-librespot[8968]: time="2026-02-18T03:43:36+07:00" level=debug msg="completed challenge" Feb 18 03:43:36 volumio go-librespot[8968]: time="2026-02-18T03:43:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:37 volumio volumio[8854]: info: Loading plugin "ytmusic"... Feb 18 03:43:37 volumio volumio-remote-updater[25144]: [2026-02-18 03:43:37] [connect] Successful connection Feb 18 03:43:38 volumio volumio[8854]: info: Loading plugin "outputs"... Feb 18 03:43:38 volumio volumio[8854]: info: Loading plugin "albumart"... Feb 18 03:43:38 volumio volumio[8854]: info: Plugin example_plugin is not enabled Feb 18 03:43:38 volumio volumio[8854]: info: Loading plugin "inputs"... Feb 18 03:43:38 volumio volumio[8854]: info: Loading plugin "updater_comm"... Feb 18 03:43:38 volumio volumio[8854]: info: Plugin mpdemulation is not enabled Feb 18 03:43:38 volumio volumio[8854]: info: Loading plugin "rest_api"... Feb 18 03:43:38 volumio volumio[8854]: info: Loading plugin "websocket"... Feb 18 03:43:38 volumio volumio[8854]: info: Starting Socket.io Server version 1.7.4 Feb 18 03:43:38 volumio volumio[8854]: info: Loading plugin "RoonBridge"... Feb 18 03:43:38 volumio volumio[8854]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 03:43:38 volumio volumio[8854]: info: Loading i18n strings for locale en Feb 18 03:43:38 volumio volumio[8854]: Updating browse sources language Feb 18 03:43:38 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:43:39 volumio volumio[8990]: Forking 3 albumart workers Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::initPlayerControls Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 03:43:39 volumio volumio[8854]: Express server listening on port 3000 Feb 18 03:43:39 volumio volumio[8854]: [Metrics] WebUI: 16s 253.49ms Feb 18 03:43:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 18 03:43:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:39 volumio volumio[8854]: info: CoreStateMachine::resetVolumioState Feb 18 03:43:39 volumio volumio[8854]: info: CoreStateMachine::getcurrentVolume Feb 18 03:43:39 volumio volumio[8854]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 03:43:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:39 volumio go-librespot[9019]: go-librespot daemon starting... Feb 18 03:43:39 volumio go-librespot[9032]: time="2026-02-18T03:43:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:39 volumio go-librespot[9032]: time="2026-02-18T03:43:39+07:00" level=debug msg="app state loaded" Feb 18 03:43:39 volumio go-librespot[9032]: time="2026-02-18T03:43:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:39 volumio sudo[9039]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 03:43:39 volumio sudo[9039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:39 volumio sudo[9039]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:39 volumio sudo[9041]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 03:43:39 volumio sudo[9041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:39 volumio sudo[9041]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:39 volumio volumio[8854]: info: Volumio Network Manager: Network status updated: 1 Feb 18 03:43:40 volumio go-librespot[9032]: time="2026-02-18T03:43:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:43:40 volumio go-librespot[9032]: time="2026-02-18T03:43:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:43:40 volumio go-librespot[9032]: time="2026-02-18T03:43:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:43:40 volumio go-librespot[9032]: time="2026-02-18T03:43:40+07:00" level=info msg="zeroconf server listening on port 41105" Feb 18 03:43:40 volumio volumio[8854]: info: VolumeController:: Volume=100 Mute =false Feb 18 03:43:40 volumio volumio[8854]: info: CoreStateMachine::pushState Feb 18 03:43:40 volumio volumio[8854]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:40 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 03:43:40 volumio volumio[8854]: info: CoreCommandRouter::volumioPushState Feb 18 03:43:40 volumio volumio[8854]: info: CoreStateMachine::updateTrackBlock Feb 18 03:43:40 volumio volumio[8854]: info: CorePlayQueue::getTrackBlock Feb 18 03:43:40 volumio volumio[8854]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 03:43:40 volumio volumio-remote-updater[25144]: [2026-02-18 03:43:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771361017 101 Feb 18 03:43:40 volumio volumio[8854]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 18 03:43:40 volumio go-librespot[9032]: time="2026-02-18T03:43:40+07:00" level=debug msg="obtained new client token: AAAs5OK8UzfzijJ6GDF1y8ym20IJ/KC7xRCe5VJlY+bBeTAVAQu27f0fdMPNlGffm6lAidb5IKAgYy5fz656p6XpLrrjy5II5oIscJ4KUFynowkf45Dlp5UeANeVVtjq1OYb5MyuYvjlCkKHoAasS1yOoXwD/aVOh+ZNQ6drHpHbyi6G8dhuc5IhUiZ2ySzDGt/1Z0RaQyhLiiL8Yxd/e6eIurQEsunJC27X0BlYZRh4VzpVySZunt2qGg==" Feb 18 03:43:40 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:40 volumio volumio[8854]: info: Reloading queue from file Feb 18 03:43:40 volumio volumio[8854]: info: CoreStateMachine::setRepeat null single undefined Feb 18 03:43:40 volumio volumio[8854]: info: CoreStateMachine::pushState Feb 18 03:43:40 volumio volumio[8854]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:40 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 03:43:40 volumio volumio[8854]: info: CoreCommandRouter::volumioPushState Feb 18 03:43:40 volumio volumio[8854]: info: CoreStateMachine::setRandom null Feb 18 03:43:40 volumio volumio[8854]: info: CoreStateMachine::pushState Feb 18 03:43:40 volumio volumio[8854]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:40 volumio volumio[8854]: info: CoreCommandRouter::volumioPushState Feb 18 03:43:40 volumio go-librespot[9032]: time="2026-02-18T03:43:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:40 volumio volumio[8854]: info: Setting Device type: Raspberry PI Feb 18 03:43:40 volumio volumio[8854]: info: Completed loading Core Plugins Feb 18 03:43:40 volumio volumio[8854]: info: Preparing to generate the ALSA configuration file Feb 18 03:43:40 volumio go-librespot[9032]: time="2026-02-18T03:43:40+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:40 volumio go-librespot[9032]: time="2026-02-18T03:43:40+07:00" level=debug msg="completed challenge" Feb 18 03:43:40 volumio volumio[8854]: info: VolumeController:: Volume=100 Mute =false Feb 18 03:43:40 volumio volumio[8854]: info: CoreStateMachine::pushState Feb 18 03:43:40 volumio volumio[8854]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:40 volumio volumio[8854]: info: CoreCommandRouter::volumioPushState Feb 18 03:43:40 volumio go-librespot[9032]: time="2026-02-18T03:43:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:40 volumio volumio[8854]: info: Asound.conf file unchanged, so no further update is needed Feb 18 03:43:40 volumio volumio[8854]: info: Output device has changed, restarting MPD Feb 18 03:43:40 volumio sudo[9059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 03:43:40 volumio sudo[9059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:40 volumio volumio[8854]: info: Output device has changed, restarting Shairport Sync Feb 18 03:43:40 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:40 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:40 volumio sudo[9062]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 03:43:40 volumio sudo[9062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:40 volumio sudo[9062]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:41 volumio sudo[9064]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 03:43:41 volumio sudo[9064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:41 volumio sudo[9059]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:41 volumio volumio[8854]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 03:43:41 volumio volumio[8854]: info: ___________ START PLUGINS ___________ Feb 18 03:43:41 volumio volumio[8854]: info: ControllerMpd::onStart: Initializing MPD Feb 18 03:43:41 volumio volumio[8854]: info: Creating MPD Configuration file Feb 18 03:43:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:43:41 volumio volumio[8854]: info: [1771361021212] CoreMusicLibrary::Adding element Media Servers Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:43:41 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 03:43:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 03:43:41 volumio systemd[1]: mpd.service: Consumed 7.138s CPU time. Feb 18 03:43:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 03:43:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 03:43:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 03:43:41 volumio sudo[9072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 03:43:41 volumio sudo[9072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:41 volumio volumio[8854]: info: UPNP Browser: Client initialized successfully Feb 18 03:43:41 volumio sudo[9072]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:41 volumio sudo[9074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:41 volumio sudo[9074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 03:43:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 03:43:41 volumio volumio[8854]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:41 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 03:43:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 03:43:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 03:43:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 03:43:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 03:43:41 volumio volumio[8854]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:43:41 volumio volumio[8854]: info: [1771361021489] CoreMusicLibrary::Adding element Last_100 Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:43:41 volumio volumio[8854]: info: [1771361021506] CoreMusicLibrary::Adding element Webradio Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 03:43:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 03:43:41 volumio volumio[8854]: info: Initializing BBC Radios Feb 18 03:43:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:41 volumio volumio[8854]: info: Creating Spotify config file Feb 18 03:43:41 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:42 volumio sudo[9090]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 03:43:42 volumio sudo[9090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 03:43:42 volumio sudo[9090]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:42 volumio volumio[9002]: Starting albumart workers Feb 18 03:43:42 volumio volumio[9001]: Starting albumart workers Feb 18 03:43:42 volumio volumio[9000]: Starting albumart workers Feb 18 03:43:42 volumio volumio[8854]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:43:42 volumio volumio[8854]: info: [1771361022824] CoreMusicLibrary::Adding element YouTube Music Feb 18 03:43:42 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:43:42 volumio volumio[8854]: Cannot find translation for source YouTube Music Feb 18 03:43:42 volumio volumio[8854]: info: Volumio Calling Home Feb 18 03:43:42 volumio sudo[9106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 03:43:42 volumio sudo[9106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:43 volumio sudo[9106]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 18 03:43:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:43 volumio volumio[8854]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 03:43:43 volumio volumio[8854]: info: Discovery: Found device Volumio Feb 18 03:43:43 volumio volumio[8854]: info: CoreCommandRouter::volumioGetState Feb 18 03:43:43 volumio volumio[8854]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:43 volumio go-librespot[9111]: go-librespot daemon starting... Feb 18 03:43:43 volumio volumio[8854]: info: MPD Permissions set Feb 18 03:43:43 volumio volumio[8854]: info: MPD Permissions set Feb 18 03:43:43 volumio volumio[8854]: info: Upmpdcli Daemon Started Feb 18 03:43:43 volumio volumio[8854]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 03:43:43 volumio volumio[8854]: info: Discovery: Found device Volumio Feb 18 03:43:43 volumio volumio[8854]: info: CoreCommandRouter::volumioGetState Feb 18 03:43:43 volumio volumio[8854]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:44 volumio volumio[8854]: info: Volumio called home Feb 18 03:43:44 volumio volumio[8854]: info: Spotify config file written Feb 18 03:43:44 volumio go-librespot[9112]: time="2026-02-18T03:43:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:44 volumio go-librespot[9112]: time="2026-02-18T03:43:44+07:00" level=debug msg="app state loaded" Feb 18 03:43:44 volumio go-librespot[9112]: time="2026-02-18T03:43:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:44 volumio volumio[8854]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 03:43:44 volumio sudo[9120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 03:43:44 volumio sudo[9120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 03:43:44 volumio systemd[1]: go-librespot-daemon.service: Killing process 9118 (go-librespot) with signal SIGKILL. Feb 18 03:43:44 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 03:43:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:44 volumio go-librespot[9133]: go-librespot daemon starting... Feb 18 03:43:44 volumio sudo[9120]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:44 volumio go-librespot[9134]: time="2026-02-18T03:43:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:44 volumio go-librespot[9134]: time="2026-02-18T03:43:44+07:00" level=debug msg="app state loaded" Feb 18 03:43:44 volumio go-librespot[9134]: time="2026-02-18T03:43:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:44 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:43:44 volumio volumio[8854]: info: No need to fix Spotify hosts Feb 18 03:43:45 volumio go-librespot[9134]: time="2026-02-18T03:43:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 03:43:45 volumio go-librespot[9134]: time="2026-02-18T03:43:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 03:43:45 volumio go-librespot[9134]: time="2026-02-18T03:43:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 03:43:45 volumio go-librespot[9134]: time="2026-02-18T03:43:45+07:00" level=info msg="zeroconf server listening on port 37639" Feb 18 03:43:45 volumio go-librespot[9134]: time="2026-02-18T03:43:45+07:00" level=debug msg="obtained new client token: AAAssTMnJZP36x9tg/1zTwLv/fvizKSDMTf/gJHMzoS2JxZSfR3lV26MJHrHMEjlsZ61a6zXtsx2Z7YUdvgoe5razJbuTE/jZa9KkiioQ6v1ghTCXO1DFCA3q//MtMceZyj3W8cJlfmF6UBv3VvnEiAYom6e519PpyS39dbd5QdHuCNdoVm7ab0mciILFRJFI8M/sWEOjzRe3ZRC3MnJpMylx7tAuh0/tyDk0ClPfvvC2HnwsGisYyslHA==" Feb 18 03:43:45 volumio go-librespot[9134]: time="2026-02-18T03:43:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:45 volumio volumio[8854]: info: Starting Shairport Sync Feb 18 03:43:45 volumio volumio[8854]: info: Starting Shairport Sync Feb 18 03:43:45 volumio volumio[8854]: info: Starting Shairport Sync Feb 18 03:43:45 volumio go-librespot[9134]: time="2026-02-18T03:43:45+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:45 volumio go-librespot[9134]: time="2026-02-18T03:43:45+07:00" level=debug msg="completed challenge" Feb 18 03:43:45 volumio sudo[9160]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 03:43:45 volumio sudo[9160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:45 volumio sudo[9162]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 03:43:45 volumio sudo[9162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:45 volumio go-librespot[9134]: time="2026-02-18T03:43:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:45 volumio sudo[9164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 03:43:45 volumio sudo[9164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:43:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:45 volumio volumio[8854]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 03:43:45 volumio volumio[8854]: SPOTIFY: BQDVwIsKltWevAFjw7belS6vG0fB9_C7Phy3IxxcyTej2tohL8PdggryO_qi-PMDo1QRYddb-99PXhu3w33BJ5yDMeyaKftWyMNSNBeBC9uqpWJw3BvlqLWabH3UeHjsnNOschHefSIGN3eu-5b7oJ3exCIcHB43Hbxp1OqmRGFzPA8jXYLj0c8CURc7z8dQZU2pluqP1x4ZZWEki-bL7KNNYqrC2bwYO67E6t4tvRNPetze3YPfklTvvmujlm0k3oyBxh1VzLjD8KBsd3nWJim7lG4vkclmZc5wkLavMAIjQlAxJQrFAuQw Feb 18 03:43:45 volumio volumio[8854]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 03:43:45 volumio volumio[8854]: info: New Spotify access token = BQDVwIsKltWevAFjw7belS6vG0fB9_C7Phy3IxxcyTej2tohL8PdggryO_qi-PMDo1QRYddb-99PXhu3w33BJ5yDMeyaKftWyMNSNBeBC9uqpWJw3BvlqLWabH3UeHjsnNOschHefSIGN3eu-5b7oJ3exCIcHB43Hbxp1OqmRGFzPA8jXYLj0c8CURc7z8dQZU2pluqP1x4ZZWEki-bL7KNNYqrC2bwYO67E6t4tvRNPetze3YPfklTvvmujlm0k3oyBxh1VzLjD8KBsd3nWJim7lG4vkclmZc5wkLavMAIjQlAxJQrFAuQw Feb 18 03:43:45 volumio volumio[8854]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 03:43:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 03:43:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 03:43:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 03:43:45 volumio systemd[1]: shairport-sync.service: Consumed 2.330s CPU time. Feb 18 03:43:45 volumio volumio[8854]: info: CoreCommandRouter::volumioGetState Feb 18 03:43:45 volumio volumio[8854]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 03:43:46 volumio sudo[9162]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:46 volumio sudo[9164]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:46 volumio sudo[9160]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:46 volumio volumio[8854]: info: Shairport-Sync Started Feb 18 03:43:46 volumio volumio[8854]: Error adding Membership: Error: addMembership EINVAL Feb 18 03:43:46 volumio volumio[8854]: info: Shairport-Sync Started Feb 18 03:43:46 volumio volumio[8854]: info: Shairport-Sync Started Feb 18 03:43:46 volumio volumio[8854]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 03:43:46 volumio volumio[8854]: info: Spotify Successfully logged in Feb 18 03:43:46 volumio volumio[8854]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:43:46 volumio volumio[8854]: info: [1771361026435] CoreMusicLibrary::Adding element Spotify Feb 18 03:43:46 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:43:46 volumio volumio[8854]: Cannot find translation for source YouTube Music Feb 18 03:43:46 volumio volumio[8854]: Cannot find translation for source Spotify Feb 18 03:43:46 volumio volumio[8854]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 03:43:46 volumio volumio[8854]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 03:43:47 volumio volumio[8854]: info: VolumeController:: Volume=100 Mute =false Feb 18 03:43:47 volumio volumio[8854]: info: CoreCommandRouter::volumioGetState Feb 18 03:43:47 volumio volumio[8854]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:47 volumio volumio[8854]: info: CoreStateMachine::pushState Feb 18 03:43:47 volumio volumio[8854]: info: CorePlayQueue::getTrack 0 Feb 18 03:43:47 volumio volumio[8854]: info: CoreCommandRouter::volumioPushState Feb 18 03:43:48 volumio volumio[8854]: info: go-librespot daemon successfully initialized Feb 18 03:43:49 volumio mpd[9103]: 2026-02-18T03:43:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 03:43:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 03:43:49 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 03:43:49 volumio sudo[9064]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:49 volumio sudo[9074]: pam_unix(sudo:session): session closed for user root Feb 18 03:43:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:49 volumio go-librespot[9203]: go-librespot daemon starting... Feb 18 03:43:49 volumio go-librespot[9205]: time="2026-02-18T03:43:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:49 volumio go-librespot[9205]: time="2026-02-18T03:43:49+07:00" level=debug msg="app state loaded" Feb 18 03:43:49 volumio go-librespot[9205]: time="2026-02-18T03:43:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:49 volumio volumio[8854]: error: MPD error: The expression evaluated to a falsy value: Feb 18 03:43:49 volumio volumio[8854]: assert.ok(self.idling) Feb 18 03:43:49 volumio volumio[8854]: error: The expression evaluated to a falsy value: Feb 18 03:43:49 volumio volumio[8854]: assert.ok(self.idling) Feb 18 03:43:49 volumio volumio[8854]: error: updateQueue error: null Feb 18 03:43:49 volumio volumio[8854]: info: MPD running with PID9103 Feb 18 03:43:49 volumio volumio[8854]: ,establishing connection Feb 18 03:43:49 volumio volumio[8854]: info: Completed starting Core Plugins Feb 18 03:43:49 volumio volumio[8854]: info: ------------------------------------------- Feb 18 03:43:49 volumio volumio[8854]: info: ----- MyVolumio plugins startup ---- Feb 18 03:43:49 volumio volumio[8854]: info: ------------------------------------------- Feb 18 03:43:49 volumio volumio[8854]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 03:43:49 volumio volumio[8854]: error: updateQueue error: null Feb 18 03:43:49 volumio go-librespot[9205]: time="2026-02-18T03:43:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:43:49 volumio go-librespot[9205]: time="2026-02-18T03:43:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:43:49 volumio go-librespot[9205]: time="2026-02-18T03:43:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:43:49 volumio go-librespot[9205]: time="2026-02-18T03:43:49+07:00" level=info msg="zeroconf server listening on port 42671" Feb 18 03:43:49 volumio go-librespot[9205]: time="2026-02-18T03:43:49+07:00" level=debug msg="obtained new client token: AABU3KFsaefKDDdUCzlN0DDb9ivOedxPzEYIb2XLiyDjN1wYK0IZyvxxYIdWibvpFfSNRttzZsGNGx+2PcbbA4qLlfpvX8XITD4T1PmeC/GlDKK4a223h3jTZsHrDk4d86e4Wkjko0wKwGMn8QHMRHkl+szP7iV+oTxdwrjGqxWPGrpoI4mk4wrkVpx/apI882yJpLWrMVnVOw0yIOD/avfKhQknqbLAAYjS78RV4Q9PYEfkPEuLT1inYQ==" Feb 18 03:43:50 volumio go-librespot[9205]: time="2026-02-18T03:43:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:50 volumio go-librespot[9205]: time="2026-02-18T03:43:50+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:50 volumio go-librespot[9205]: time="2026-02-18T03:43:50+07:00" level=debug msg="completed challenge" Feb 18 03:43:50 volumio go-librespot[9205]: time="2026-02-18T03:43:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:51 volumio volumio[8854]: info: Initializing connection to go-librespot Websocket Feb 18 03:43:51 volumio volumio[8854]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:43:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 03:43:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:53 volumio go-librespot[9214]: go-librespot daemon starting... Feb 18 03:43:53 volumio go-librespot[9215]: time="2026-02-18T03:43:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:53 volumio go-librespot[9215]: time="2026-02-18T03:43:53+07:00" level=debug msg="app state loaded" Feb 18 03:43:53 volumio go-librespot[9215]: time="2026-02-18T03:43:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:53 volumio go-librespot[9215]: time="2026-02-18T03:43:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:43:53 volumio go-librespot[9215]: time="2026-02-18T03:43:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:43:53 volumio go-librespot[9215]: time="2026-02-18T03:43:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:43:53 volumio go-librespot[9215]: time="2026-02-18T03:43:53+07:00" level=info msg="zeroconf server listening on port 42027" Feb 18 03:43:54 volumio volumio[8854]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 03:43:54 volumio go-librespot[9215]: time="2026-02-18T03:43:54+07:00" level=debug msg="obtained new client token: AACUW5k3L9ykmtPFd0uDIiSIorXr+mPWhaHTzoNQ33e3pZMp4sNYJE30sSPWrmlUuL6/oC7s7ZLxPgh7mxIj2PDazwnOsObJ/u3Bsw/9xCzEqEy3KMEXZYrN787cyQb522fErvfthl5bWzY3qK8dMGNqVmeLvFiSMmuMc7XlrjRaiV9FO4T+FQ7J9k6b1T4+0rTqkvwPS52fqWfEl/B2Jp0tcjMMlCmW64TZuJhpifY2M4j15d67I+M=" Feb 18 03:43:54 volumio go-librespot[9215]: time="2026-02-18T03:43:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:54 volumio go-librespot[9215]: time="2026-02-18T03:43:54+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:54 volumio go-librespot[9215]: time="2026-02-18T03:43:54+07:00" level=debug msg="completed challenge" Feb 18 03:43:54 volumio go-librespot[9215]: time="2026-02-18T03:43:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:54 volumio volumio[8854]: info: Initializing connection to go-librespot Websocket Feb 18 03:43:54 volumio volumio[8854]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:43:57 volumio volumio[8854]: info: Initializing connection to go-librespot Websocket Feb 18 03:43:57 volumio volumio[8854]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:43:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 03:43:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:43:57 volumio go-librespot[9223]: go-librespot daemon starting... Feb 18 03:43:57 volumio go-librespot[9224]: time="2026-02-18T03:43:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:43:57 volumio go-librespot[9224]: time="2026-02-18T03:43:57+07:00" level=debug msg="app state loaded" Feb 18 03:43:57 volumio go-librespot[9224]: time="2026-02-18T03:43:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 03:43:58 volumio volumio[8854]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 03:43:58 volumio volumio[8854]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 03:43:58 volumio volumio[8854]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 03:43:58 volumio volumio[8854]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 03:43:58 volumio volumio[8854]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 03:43:58 volumio volumio[8854]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 03:43:58 volumio volumio[8854]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 03:43:58 volumio volumio[8854]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 03:43:58 volumio go-librespot[9224]: time="2026-02-18T03:43:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:43:58 volumio go-librespot[9224]: time="2026-02-18T03:43:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:43:58 volumio go-librespot[9224]: time="2026-02-18T03:43:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:43:58 volumio go-librespot[9224]: time="2026-02-18T03:43:58+07:00" level=info msg="zeroconf server listening on port 38113" Feb 18 03:43:58 volumio go-librespot[9224]: time="2026-02-18T03:43:58+07:00" level=debug msg="obtained new client token: AAAGS8BSoPtvuZEIliEQ6l+Q4URlHM1DpbL5sfOLuhn14PSXzXlltsLrjonmSTgww9BbnxyhBQ+P2KBqwV7qJJHdZLHSMg3v7IC93ZljXOIRTcY7M7lB+wSY0MsP86gJv3IAJGXtxpGc8mj1hTdpDrw9S5kIt7bJwJc0FLTvHBrSMQUgdZ0Sy2OBe+dcZhb/W7n+V6oF/HAymPvQjsaTGrXZqAPdGXbbcWUrj4NosO+pLuHjMllOA1d+8w==" Feb 18 03:43:58 volumio go-librespot[9224]: time="2026-02-18T03:43:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:43:58 volumio go-librespot[9224]: time="2026-02-18T03:43:58+07:00" level=debug msg="completed keyexchange" Feb 18 03:43:58 volumio go-librespot[9224]: time="2026-02-18T03:43:58+07:00" level=debug msg="completed challenge" Feb 18 03:43:58 volumio go-librespot[9224]: time="2026-02-18T03:43:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:43:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:43:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:43:59 volumio volumio[8854]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 03:43:59 volumio volumio[8854]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 03:43:59 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:59 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:43:59 volumio volumio[8854]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 03:43:59 volumio volumio[8854]: info: MyVolumio login type: Token Feb 18 03:44:00 volumio volumio[8854]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 03:44:00 volumio volumio[8854]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 03:44:01 volumio volumio[8854]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 03:44:01 volumio volumio[8854]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 03:44:01 volumio volumio[8854]: info: Streaming services startup Feb 18 03:44:01 volumio volumio[8854]: info: Starting Streaming Daemon Feb 18 03:44:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 03:44:01 volumio sudo[9246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 03:44:01 volumio volumio[8854]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 03:44:01 volumio sudo[9246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:01 volumio volumio[8854]: info: Initializing connection to go-librespot Websocket Feb 18 03:44:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:01 volumio go-librespot[9252]: go-librespot daemon starting... Feb 18 03:44:01 volumio volumio[8854]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:44:02 volumio sudo[9246]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:02 volumio volumio[8854]: error: Cannot start Volumio Streaming Daemon Feb 18 03:44:02 volumio volumio[8854]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 03:44:02 volumio volumio[8854]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=debug msg="app state loaded" Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=info msg="zeroconf server listening on port 33311" Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=debug msg="obtained new client token: AAA/AMeGeoIOu9+LUGRGszATqckWIKbhcit+mN87kHxhO/Uy/zZ0uZ1cUmyw17phzt3o6cp4GHNLRwz9CbTfsDre+LXKdDNW8Lh2rxNAwyBCsAFzs3hkI4yWOTDYq7ann4HgcGWhaHCrTbmxfIGtckJ2H2SzC/XV6uMtZvqIdNLziEP2cNvo/7nw6h217o/8ziMMLuIRco2xDI664juR02COgNgRzCyJM90IqT54Q/KXJs7MHoQP8qcjVQ==" Feb 18 03:44:02 volumio volumio[8854]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:02 volumio go-librespot[9254]: time="2026-02-18T03:44:02+07:00" level=debug msg="completed challenge" Feb 18 03:44:03 volumio go-librespot[9254]: time="2026-02-18T03:44:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:03 volumio volumio[8854]: info: MyVolumio token set successfully Feb 18 03:44:03 volumio volumio[8854]: info: MYVOLUMIO: Adding device Feb 18 03:44:03 volumio volumio[8854]: info: MYVOLUMIO: Evaluating Server Feb 18 03:44:04 volumio volumio[8854]: info: MyVolumio status changed Feb 18 03:44:04 volumio volumio[8854]: info: Streaming services startup Feb 18 03:44:04 volumio volumio[8854]: info: Starting Streaming Daemon Feb 18 03:44:04 volumio volumio[8854]: info: Removing browser output: myVolumio user plan is not superstar Feb 18 03:44:04 volumio volumio[8854]: info: Removing audio output: Feb 18 03:44:04 volumio volumio[8854]: info: Stoppping Tunnel 1 Feb 18 03:44:04 volumio sudo[9283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 03:44:04 volumio sudo[9283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:04 volumio sudo[9283]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:04 volumio sudo[9286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 18 03:44:04 volumio sudo[9286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:04 volumio volumio[8854]: error: Cannot start Volumio Streaming Daemon Feb 18 03:44:04 volumio volumio[8854]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 03:44:04 volumio volumio[8854]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 03:44:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 03:44:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 03:44:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 03:44:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 03:44:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 03:44:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 03:44:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 03:44:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 03:44:04 volumio sudo[9286]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:04 volumio volumio[8854]: info: Remote SSH Stopped Feb 18 03:44:04 volumio volumio[8854]: info: Initializing connection to go-librespot Websocket Feb 18 03:44:04 volumio volumio[8854]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:44:05 volumio volumio[8854]: info: Setting Geolocation for MyVolumio to as1 Feb 18 03:44:05 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:05 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:05 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 03:44:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:06 volumio volumio[8854]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 18 03:44:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:06 volumio go-librespot[9288]: go-librespot daemon starting... Feb 18 03:44:06 volumio go-librespot[9289]: time="2026-02-18T03:44:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:06 volumio go-librespot[9289]: time="2026-02-18T03:44:06+07:00" level=debug msg="app state loaded" Feb 18 03:44:06 volumio go-librespot[9289]: time="2026-02-18T03:44:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:06 volumio go-librespot[9289]: time="2026-02-18T03:44:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:44:06 volumio go-librespot[9289]: time="2026-02-18T03:44:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:44:06 volumio go-librespot[9289]: time="2026-02-18T03:44:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:44:06 volumio go-librespot[9289]: time="2026-02-18T03:44:06+07:00" level=info msg="zeroconf server listening on port 33179" Feb 18 03:44:06 volumio volumio[8854]: info: Updating MyVolumio device info Feb 18 03:44:06 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:06 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:06 volumio volumio[8854]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:07 volumio go-librespot[9289]: time="2026-02-18T03:44:07+07:00" level=debug msg="obtained new client token: AACov0S2gih7A0Bdb79YYpbe12qU0Ba5v61T9vSrwkgsftxQowZA1Ko+x/HS76H5Ln2qGiv6SaJegJetvYx976mjs3vOdxNHtZJpyhRlLgfXxAShoAb6nYBbFhMu+XFUYGNBFLgsSEmzWj4aSvQi5OGXPGjWByF2XJv7/k5ikx/NvTCW+znc/w0yygZPwxPqhRyPccjUGgBnDcVBt3GOPucU5EDc4NadEK3f1iOXYL1a3T/EXINdo98=" Feb 18 03:44:07 volumio go-librespot[9289]: time="2026-02-18T03:44:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:08 volumio volumio[8854]: info: Initializing connection to go-librespot Websocket Feb 18 03:44:08 volumio go-librespot[9289]: time="2026-02-18T03:44:08+07:00" level=debug msg="new websocket client" Feb 18 03:44:08 volumio volumio[8854]: info: Connection to go-librespot Websocket established Feb 18 03:44:08 volumio go-librespot[9289]: time="2026-02-18T03:44:08+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:08 volumio go-librespot[9289]: time="2026-02-18T03:44:08+07:00" level=debug msg="completed challenge" Feb 18 03:44:08 volumio go-librespot[9289]: time="2026-02-18T03:44:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:08 volumio volumio[8854]: info: Connection to go-librespot Websocket closed Feb 18 03:44:08 volumio volumio[8854]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 18 03:44:10 volumio volumio[8854]: info: MYVOLUMIO: Adding device Feb 18 03:44:10 volumio volumio[8854]: info: MYVOLUMIO: Evaluating Server Feb 18 03:44:11 volumio volumio[8854]: info: Getting Spotify volume Feb 18 03:44:11 volumio volumio[8854]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 03:44:11 volumio volumio[8854]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:44:11 volumio volumio[8854]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 03:44:11 volumio volumio[8854]: errno: -111, Feb 18 03:44:11 volumio volumio[8854]: code: 'ECONNREFUSED', Feb 18 03:44:11 volumio volumio[8854]: syscall: 'connect', Feb 18 03:44:11 volumio volumio[8854]: address: '127.0.0.1', Feb 18 03:44:11 volumio volumio[8854]: port: 9879, Feb 18 03:44:11 volumio volumio[8854]: response: undefined Feb 18 03:44:11 volumio volumio[8854]: } Feb 18 03:44:11 volumio volumio[8854]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 03:44:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 03:44:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:11 volumio go-librespot[9341]: go-librespot daemon starting... Feb 18 03:44:11 volumio go-librespot[9342]: time="2026-02-18T03:44:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:11 volumio go-librespot[9342]: time="2026-02-18T03:44:11+07:00" level=debug msg="app state loaded" Feb 18 03:44:11 volumio go-librespot[9342]: time="2026-02-18T03:44:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:11 volumio go-librespot[9342]: time="2026-02-18T03:44:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 03:44:11 volumio go-librespot[9342]: time="2026-02-18T03:44:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 03:44:11 volumio go-librespot[9342]: time="2026-02-18T03:44:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 03:44:11 volumio go-librespot[9342]: time="2026-02-18T03:44:11+07:00" level=info msg="zeroconf server listening on port 33577" Feb 18 03:44:12 volumio go-librespot[9342]: time="2026-02-18T03:44:12+07:00" level=debug msg="obtained new client token: AAAWaRdVeM8QmVcCMWVxXd7jAGxtHsCiUU0OdsFuCce49uM/4SmXXfP+zDf3CeN5f99COg36xUz9IaNLmgf/xn56732FRWQv99tv+6hrDq+e8ZdMsCexJ65u5G7CqaLEKh0HD7pIU5WHqC8Q/MQdj0CR+XJ/A0jgu3e+hztktQYAfUd/VUjjpukBeN/UjzL/mC4mTYB5SWRZ5N7HxjGYV2QYEV2ZLgdFx5k20E1yDJlm539sfTW92Mk=" Feb 18 03:44:12 volumio go-librespot[9342]: time="2026-02-18T03:44:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:12 volumio go-librespot[9342]: time="2026-02-18T03:44:12+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:12 volumio go-librespot[9342]: time="2026-02-18T03:44:12+07:00" level=debug msg="completed challenge" Feb 18 03:44:12 volumio sudo[9351]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 03:43' Feb 18 03:44:12 volumio sudo[9351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:12 volumio go-librespot[9342]: time="2026-02-18T03:44:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:12 volumio sudo[9351]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:12 volumio volumio-remote-updater[25144]: [2026-02-18 03:44:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 03:44:12 volumio volumio-remote-updater[25144]: [2026-02-18 03:44:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 03:44:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 03:44:13 volumio systemd[1]: volumio.service: Consumed 57.953s CPU time. Feb 18 03:44:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 03:44:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 03:44:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21314. Feb 18 03:44:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 03:44:13 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 03:44:13 volumio systemd[1]: volumio.service: Consumed 57.953s CPU time. Feb 18 03:44:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 03:44:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 03:44:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 03:44:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:15 volumio go-librespot[9383]: go-librespot daemon starting... Feb 18 03:44:15 volumio go-librespot[9384]: time="2026-02-18T03:44:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:15 volumio go-librespot[9384]: time="2026-02-18T03:44:15+07:00" level=debug msg="app state loaded" Feb 18 03:44:15 volumio go-librespot[9384]: time="2026-02-18T03:44:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:16 volumio go-librespot[9384]: time="2026-02-18T03:44:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:44:16 volumio go-librespot[9384]: time="2026-02-18T03:44:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:44:16 volumio go-librespot[9384]: time="2026-02-18T03:44:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:44:16 volumio go-librespot[9384]: time="2026-02-18T03:44:16+07:00" level=info msg="zeroconf server listening on port 46483" Feb 18 03:44:16 volumio go-librespot[9384]: time="2026-02-18T03:44:16+07:00" level=debug msg="obtained new client token: AADeLDFRYELVa92MLZ3iYDAk3d513R3qDf56C6SAU0SqjIxoYS93YyCMOqtmdM9Bd3Q1X2WrxxsdlKz5mk8pejCT2bS4be38bnrmzlPQ9PBgIVmDR4bWhFdFQE8DaRJr/X9HoXpkLb7PX7Z40NYWmUFQeKDyDZxIbQQmFrdXouA5ZsraY0pdUY3Jh6pqSKYXLwgaDFrWLbY26W2DiFHd5py7eOtnduRn9IBTADONmNUHaO8w43qFoPzXKQ==" Feb 18 03:44:16 volumio volumio[9368]: info: ------------------------------------------- Feb 18 03:44:16 volumio volumio[9368]: info: ----- Volumio3 ---- Feb 18 03:44:16 volumio volumio[9368]: info: ------------------------------------------- Feb 18 03:44:16 volumio volumio[9368]: info: ----- System startup ---- Feb 18 03:44:16 volumio volumio[9368]: info: ------------------------------------------- Feb 18 03:44:16 volumio go-librespot[9384]: time="2026-02-18T03:44:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:16 volumio go-librespot[9384]: time="2026-02-18T03:44:16+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:16 volumio go-librespot[9384]: time="2026-02-18T03:44:16+07:00" level=debug msg="completed challenge" Feb 18 03:44:17 volumio go-librespot[9384]: time="2026-02-18T03:44:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:17 volumio volumio-remote-updater[25144]: [2026-02-18 03:44:17] [connect] Successful connection Feb 18 03:44:18 volumio volumio[9368]: info: MYVOLUMIO Environment detected Feb 18 03:44:18 volumio volumio[9368]: info: Plugin folders cleanup Feb 18 03:44:18 volumio volumio[9368]: info: Scanning into folder /volumio/app/plugins/ Feb 18 03:44:18 volumio volumio[9368]: info: Scanning category audio_interface Feb 18 03:44:18 volumio volumio[9368]: info: Scanning category miscellanea Feb 18 03:44:18 volumio volumio[9368]: info: Scanning category music_service Feb 18 03:44:18 volumio volumio[9368]: info: Scanning category plugins.json Feb 18 03:44:18 volumio volumio[9368]: info: Scanning category system_controller Feb 18 03:44:18 volumio volumio[9368]: info: Scanning category user_interface Feb 18 03:44:18 volumio volumio[9368]: info: Scanning into folder /data/plugins/ Feb 18 03:44:18 volumio volumio[9368]: info: Scanning category music_service Feb 18 03:44:18 volumio volumio[9368]: info: Plugin folders cleanup completed Feb 18 03:44:18 volumio volumio[9368]: info: ------------------------------------------- Feb 18 03:44:18 volumio volumio[9368]: info: ----- Core plugins startup ---- Feb 18 03:44:18 volumio volumio[9368]: info: ------------------------------------------- Feb 18 03:44:18 volumio volumio[9368]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 03:44:18 volumio volumio[9368]: info: Adding plugin upnp to MyMusic Plugins Feb 18 03:44:18 volumio volumio[9368]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 03:44:18 volumio volumio[9368]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 03:44:18 volumio volumio[9368]: info: Loading plugins from folder /data/plugins/ Feb 18 03:44:18 volumio volumio[9368]: info: Loading plugin "system"... Feb 18 03:44:18 volumio volumio[9368]: info: Loading plugin "appearance"... Feb 18 03:44:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 03:44:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:20 volumio go-librespot[9404]: go-librespot daemon starting... Feb 18 03:44:20 volumio go-librespot[9405]: time="2026-02-18T03:44:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:20 volumio go-librespot[9405]: time="2026-02-18T03:44:20+07:00" level=debug msg="app state loaded" Feb 18 03:44:20 volumio go-librespot[9405]: time="2026-02-18T03:44:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:20 volumio volumio[9368]: info: Loading plugin "network"... Feb 18 03:44:20 volumio volumio[9368]: info: Refreshing Cached IP Addresses Feb 18 03:44:20 volumio sudo[9412]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 03:44:20 volumio sudo[9412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:20 volumio sudo[9414]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 03:44:20 volumio sudo[9414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:20 volumio sudo[9412]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:20 volumio sudo[9414]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:20 volumio volumio[9368]: info: Loading plugin "services"... Feb 18 03:44:20 volumio volumio[9368]: info: Loading plugin "alsa_controller"... Feb 18 03:44:20 volumio sudo[9422]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 03:44:20 volumio sudo[9422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:20 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 03:44:20 volumio volumio[9368]: info: Loading plugin "wizard"... Feb 18 03:44:20 volumio volumio[9368]: info: Loading plugin "networkfs"... Feb 18 03:44:20 volumio volumio[9368]: info: Starting Udev Watcher for removable devices Feb 18 03:44:20 volumio volumio[9368]: info: Ignoring mount for partition: boot Feb 18 03:44:20 volumio volumio[9368]: info: Ignoring mount for partition: volumio Feb 18 03:44:20 volumio volumio[9368]: info: Ignoring mount for partition: volumio_data Feb 18 03:44:20 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 03:44:20 volumio volumio[9368]: info: Loading plugin "volumio_command_line_client"... Feb 18 03:44:20 volumio volumio[9368]: info: Loading plugin "upnp"... Feb 18 03:44:20 volumio volumio[9368]: info: [1771361060704] Starting Upmpd Daemon Feb 18 03:44:20 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 03:44:20 volumio volumio[9368]: info: Loading plugin "my_music"... Feb 18 03:44:20 volumio volumio[9368]: info: Loading plugin "mpd"... Feb 18 03:44:20 volumio go-librespot[9405]: time="2026-02-18T03:44:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:44:20 volumio go-librespot[9405]: time="2026-02-18T03:44:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:44:20 volumio go-librespot[9405]: time="2026-02-18T03:44:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:44:20 volumio go-librespot[9405]: time="2026-02-18T03:44:20+07:00" level=info msg="zeroconf server listening on port 41895" Feb 18 03:44:20 volumio go-librespot[9405]: time="2026-02-18T03:44:20+07:00" level=debug msg="obtained new client token: AAClYfnddqjAaB/ZxSznZWYzlqox5I5RV1YjKNEpUjevoQf0Y2fqk8sktLtpZRNn17UIwhQ80chJCZ8/WVMPvVd2/TE7HzoA2gCdtJUYHvtz2cMLWWxdqCrzwOOVScWYCtJ97tHv9USyD7cDRbd5IGkYGHsn8frenlOD6LEpCQxyk1koOO0jL9dNImK+BS3zUxNiIujNv7gxT9mapnBPYXx0lRHM2luHUj7foKJth64h5TqAIrdvl6tNCg==" Feb 18 03:44:21 volumio go-librespot[9405]: time="2026-02-18T03:44:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:21 volumio go-librespot[9405]: time="2026-02-18T03:44:21+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:21 volumio go-librespot[9405]: time="2026-02-18T03:44:21+07:00" level=debug msg="completed challenge" Feb 18 03:44:21 volumio go-librespot[9405]: time="2026-02-18T03:44:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:21 volumio volumio[9368]: info: Loading plugin "upnp_browser"... Feb 18 03:44:23 volumio sudo[9422]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:24 volumio volumio[9368]: info: Starting UPNP Browser Feb 18 03:44:24 volumio volumio[9368]: info: Loading plugin "alarm-clock"... Feb 18 03:44:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 03:44:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:24 volumio go-librespot[9448]: go-librespot daemon starting... Feb 18 03:44:24 volumio go-librespot[9449]: time="2026-02-18T03:44:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:24 volumio go-librespot[9449]: time="2026-02-18T03:44:24+07:00" level=debug msg="app state loaded" Feb 18 03:44:24 volumio volumio[9368]: info: Loading plugin "airplay_emulation"... Feb 18 03:44:24 volumio go-librespot[9449]: time="2026-02-18T03:44:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:24 volumio volumio[9368]: info: Starting Shairport Sync Feb 18 03:44:24 volumio volumio[9368]: info: Loading plugin "last_100"... Feb 18 03:44:24 volumio volumio[9368]: info: Loading plugin "webradio"... Feb 18 03:44:24 volumio volumio[9368]: info: Loading plugin "i2s_dacs"... Feb 18 03:44:24 volumio volumio[9368]: info: Loading plugin "volumiodiscovery"... Feb 18 03:44:25 volumio volumio[9368]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 03:44:25 volumio volumio[9368]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 03:44:25 volumio volumio[9368]: *** WARNING *** For more information see Feb 18 03:44:25 volumio volumio[9368]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 03:44:25 volumio volumio[9368]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 03:44:25 volumio volumio[9368]: *** WARNING *** For more information see Feb 18 03:44:25 volumio node[9368]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 03:44:25 volumio node[9368]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 03:44:25 volumio node[9368]: *** WARNING *** For more information see Feb 18 03:44:25 volumio node[9368]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 03:44:25 volumio node[9368]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 03:44:25 volumio node[9368]: *** WARNING *** For more information see Feb 18 03:44:25 volumio volumio[9368]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 03:44:25 volumio volumio[9368]: info: Discovery: Started advertising with name: Volumio Feb 18 03:44:25 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 03:44:25 volumio volumio[9368]: info: Loading plugin "spop"... Feb 18 03:44:25 volumio go-librespot[9449]: time="2026-02-18T03:44:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:44:25 volumio go-librespot[9449]: time="2026-02-18T03:44:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:44:25 volumio go-librespot[9449]: time="2026-02-18T03:44:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:44:25 volumio go-librespot[9449]: time="2026-02-18T03:44:25+07:00" level=info msg="zeroconf server listening on port 44977" Feb 18 03:44:25 volumio go-librespot[9449]: time="2026-02-18T03:44:25+07:00" level=debug msg="obtained new client token: AACt897GdjgZjOpKa/65rvE3Iwc4VxE2+wY4koTCP1wOFXbaluHWZerRFu9F/MxjODZEnIzuerMVHZJ7JSMFtEU2HuqMpIP77txluHSOvnxeRCKbx7PcM4wBkWWsGFJWjAyU/q2uS564PTQ9vTZf0iHDwRCExtaKgQM2Opk2d25bmECUNN1LT1d9hzQ4q5UnJqTUSwxB8N593TzJRlypIup/+d1UXtlLJHNRlXWS/A2CdZdMQRnzmqrK2Q==" Feb 18 03:44:25 volumio go-librespot[9449]: time="2026-02-18T03:44:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:25 volumio go-librespot[9449]: time="2026-02-18T03:44:25+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:25 volumio go-librespot[9449]: time="2026-02-18T03:44:25+07:00" level=debug msg="completed challenge" Feb 18 03:44:25 volumio go-librespot[9449]: time="2026-02-18T03:44:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:26 volumio volumio[9368]: info: Loading plugin "ytcr"... Feb 18 03:44:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 03:44:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:29 volumio go-librespot[9458]: go-librespot daemon starting... Feb 18 03:44:29 volumio go-librespot[9459]: time="2026-02-18T03:44:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:29 volumio go-librespot[9459]: time="2026-02-18T03:44:29+07:00" level=debug msg="app state loaded" Feb 18 03:44:29 volumio go-librespot[9459]: time="2026-02-18T03:44:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:29 volumio volumio[9368]: info: Loading plugin "ytmusic"... Feb 18 03:44:29 volumio go-librespot[9459]: time="2026-02-18T03:44:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 03:44:29 volumio go-librespot[9459]: time="2026-02-18T03:44:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 03:44:29 volumio go-librespot[9459]: time="2026-02-18T03:44:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 03:44:29 volumio go-librespot[9459]: time="2026-02-18T03:44:29+07:00" level=info msg="zeroconf server listening on port 41533" Feb 18 03:44:29 volumio go-librespot[9459]: time="2026-02-18T03:44:29+07:00" level=debug msg="obtained new client token: AAAfwdtDDcFfviSRojC6HiznQ1R5Ve5t58ftQ4ZPt4JGGWrG82MhpAeg/WJeyTonzFtNuop7WnrQLBZs3q/yb4XcnNBwRU2eSkOii6tJbC8RLleNqonrtq2oCOPrhgHZdbD0k5tKYqMKYlJWG/isuJaTdbfj1Wt7oo6PqB+i7yiP/PLkWQF8L6fdVxf0fOu7dUezODmKxwDHQZrbiWA7cDXCAbf376tVcCZ5IwWhDqEyerlYGj3PMrd50A==" Feb 18 03:44:30 volumio go-librespot[9459]: time="2026-02-18T03:44:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:30 volumio go-librespot[9459]: time="2026-02-18T03:44:30+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:30 volumio go-librespot[9459]: time="2026-02-18T03:44:30+07:00" level=debug msg="completed challenge" Feb 18 03:44:30 volumio go-librespot[9459]: time="2026-02-18T03:44:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:30 volumio volumio-remote-updater[25144]: [2026-02-18 03:44:30] [connect] Successful connection Feb 18 03:44:30 volumio volumio[9368]: info: Loading plugin "outputs"... Feb 18 03:44:30 volumio volumio[9368]: info: Loading plugin "albumart"... Feb 18 03:44:30 volumio volumio[9368]: info: Plugin example_plugin is not enabled Feb 18 03:44:30 volumio volumio[9368]: info: Loading plugin "inputs"... Feb 18 03:44:30 volumio volumio[9368]: info: Loading plugin "updater_comm"... Feb 18 03:44:30 volumio volumio[9368]: info: Plugin mpdemulation is not enabled Feb 18 03:44:30 volumio volumio[9368]: info: Loading plugin "rest_api"... Feb 18 03:44:30 volumio volumio[9368]: info: Loading plugin "websocket"... Feb 18 03:44:30 volumio volumio[9368]: info: Starting Socket.io Server version 1.7.4 Feb 18 03:44:30 volumio volumio[9368]: info: Loading plugin "RoonBridge"... Feb 18 03:44:31 volumio volumio[9368]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 03:44:31 volumio volumio[9368]: info: Loading i18n strings for locale en Feb 18 03:44:31 volumio volumio[9368]: Updating browse sources language Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::initPlayerControls Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 03:44:31 volumio volumio[9368]: Express server listening on port 3000 Feb 18 03:44:31 volumio volumio[9368]: [Metrics] WebUI: 16s 18.36ms Feb 18 03:44:31 volumio volumio[9480]: Forking 3 albumart workers Feb 18 03:44:31 volumio volumio[9368]: info: CoreStateMachine::resetVolumioState Feb 18 03:44:31 volumio volumio[9368]: info: CoreStateMachine::getcurrentVolume Feb 18 03:44:31 volumio volumio[9368]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 03:44:31 volumio sudo[9498]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 03:44:31 volumio sudo[9498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:31 volumio sudo[9498]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:32 volumio sudo[9507]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 03:44:32 volumio sudo[9507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:32 volumio volumio[9368]: info: Volumio Network Manager: Network status updated: 1 Feb 18 03:44:32 volumio sudo[9507]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:32 volumio volumio[9368]: info: VolumeController:: Volume=100 Mute =false Feb 18 03:44:32 volumio volumio[9368]: info: CoreStateMachine::pushState Feb 18 03:44:32 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:32 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 03:44:32 volumio volumio[9368]: info: CoreCommandRouter::volumioPushState Feb 18 03:44:32 volumio volumio[9368]: info: CoreStateMachine::updateTrackBlock Feb 18 03:44:32 volumio volumio[9368]: info: CorePlayQueue::getTrackBlock Feb 18 03:44:32 volumio volumio[9368]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 03:44:32 volumio volumio-remote-updater[25144]: [2026-02-18 03:44:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771361070 101 Feb 18 03:44:32 volumio volumio[9368]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 18 03:44:32 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:32 volumio volumio[9368]: info: Reloading queue from file Feb 18 03:44:32 volumio volumio[9368]: info: CoreStateMachine::setRepeat null single undefined Feb 18 03:44:32 volumio volumio[9368]: info: CoreStateMachine::pushState Feb 18 03:44:32 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:32 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 03:44:32 volumio volumio[9368]: info: CoreCommandRouter::volumioPushState Feb 18 03:44:32 volumio volumio[9368]: info: CoreStateMachine::setRandom null Feb 18 03:44:32 volumio volumio[9368]: info: CoreStateMachine::pushState Feb 18 03:44:32 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:32 volumio volumio[9368]: info: CoreCommandRouter::volumioPushState Feb 18 03:44:32 volumio volumio[9368]: info: Setting Device type: Raspberry PI Feb 18 03:44:32 volumio volumio[9368]: info: Completed loading Core Plugins Feb 18 03:44:32 volumio volumio[9368]: info: Preparing to generate the ALSA configuration file Feb 18 03:44:32 volumio volumio[9368]: info: VolumeController:: Volume=100 Mute =false Feb 18 03:44:32 volumio volumio[9368]: info: CoreStateMachine::pushState Feb 18 03:44:32 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:32 volumio volumio[9368]: info: CoreCommandRouter::volumioPushState Feb 18 03:44:32 volumio volumio[9368]: info: Asound.conf file unchanged, so no further update is needed Feb 18 03:44:32 volumio volumio[9368]: info: Output device has changed, restarting MPD Feb 18 03:44:32 volumio volumio[9368]: info: Output device has changed, restarting Shairport Sync Feb 18 03:44:32 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:32 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:32 volumio sudo[9541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 03:44:32 volumio sudo[9541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:32 volumio sudo[9545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 03:44:32 volumio sudo[9545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:32 volumio sudo[9543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 03:44:32 volumio sudo[9543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:33 volumio volumio[9368]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 03:44:33 volumio sudo[9543]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:33 volumio volumio[9368]: info: ___________ START PLUGINS ___________ Feb 18 03:44:33 volumio volumio[9368]: info: ControllerMpd::onStart: Initializing MPD Feb 18 03:44:33 volumio volumio[9368]: info: Creating MPD Configuration file Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:44:33 volumio volumio[9368]: info: [1771361073094] CoreMusicLibrary::Adding element Media Servers Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:44:33 volumio volumio[9368]: info: UPNP Browser: Client initialized successfully Feb 18 03:44:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 03:44:33 volumio sudo[9541]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:33 volumio sudo[9554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:33 volumio sudo[9554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:33 volumio sudo[9554]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:33 volumio sudo[9556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 03:44:33 volumio sudo[9556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 03:44:33 volumio volumio[9368]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 03:44:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 03:44:33 volumio systemd[1]: mpd.service: Consumed 7.116s CPU time. Feb 18 03:44:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 03:44:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 03:44:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 03:44:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 03:44:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:33 volumio volumio[9368]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 03:44:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:44:33 volumio volumio[9368]: info: [1771361073374] CoreMusicLibrary::Adding element Last_100 Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:44:33 volumio go-librespot[9568]: go-librespot daemon starting... Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:44:33 volumio volumio[9368]: info: [1771361073387] CoreMusicLibrary::Adding element Webradio Feb 18 03:44:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 03:44:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 03:44:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 03:44:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 03:44:33 volumio volumio[9368]: info: Initializing BBC Radios Feb 18 03:44:33 volumio go-librespot[9569]: time="2026-02-18T03:44:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:33 volumio go-librespot[9569]: time="2026-02-18T03:44:33+07:00" level=debug msg="app state loaded" Feb 18 03:44:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 03:44:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 03:44:33 volumio go-librespot[9569]: time="2026-02-18T03:44:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 03:44:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:33 volumio volumio[9368]: info: Creating Spotify config file Feb 18 03:44:33 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:34 volumio sudo[9585]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 03:44:34 volumio sudo[9585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 03:44:34 volumio sudo[9585]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:34 volumio go-librespot[9569]: time="2026-02-18T03:44:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:44:34 volumio go-librespot[9569]: time="2026-02-18T03:44:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:44:34 volumio go-librespot[9569]: time="2026-02-18T03:44:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:44:34 volumio go-librespot[9569]: time="2026-02-18T03:44:34+07:00" level=info msg="zeroconf server listening on port 44651" Feb 18 03:44:34 volumio go-librespot[9569]: time="2026-02-18T03:44:34+07:00" level=debug msg="obtained new client token: AADOrSnIEVAXG120H2OdkaCOt2Jjn9Ze7PHnJ4sVvuBdoFtw4pBgjf/EOvTBBqMEj15S9aGO5KSnAF+wiZE5jkUmGFI9p+Xgs4zRUnKfo/3BVLcIJHgAvdPgW8yxbGeb+W9Gyo5mvyMyO7jFcXCLyQmNHkS4dQfHR7D1RtxThSCh0o4FcbVmREC72J2LHeCvnD4OFxvK8uGOmss3NiDf5ks5r/upj+xUyHn+Zp9jeBlIcIa6lvvxgEwiyQ==" Feb 18 03:44:34 volumio go-librespot[9569]: time="2026-02-18T03:44:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:34 volumio go-librespot[9569]: time="2026-02-18T03:44:34+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:34 volumio go-librespot[9569]: time="2026-02-18T03:44:34+07:00" level=debug msg="completed challenge" Feb 18 03:44:34 volumio go-librespot[9569]: time="2026-02-18T03:44:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:35 volumio volumio[9368]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:44:35 volumio volumio[9368]: info: [1771361075178] CoreMusicLibrary::Adding element YouTube Music Feb 18 03:44:35 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:44:35 volumio volumio[9368]: Cannot find translation for source YouTube Music Feb 18 03:44:35 volumio volumio[9496]: Starting albumart workers Feb 18 03:44:35 volumio volumio[9368]: info: Volumio Calling Home Feb 18 03:44:35 volumio sudo[9596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 03:44:35 volumio sudo[9596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:35 volumio sudo[9596]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:35 volumio volumio[9495]: Starting albumart workers Feb 18 03:44:35 volumio volumio[9494]: Starting albumart workers Feb 18 03:44:35 volumio volumio[9368]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 03:44:35 volumio volumio[9368]: info: Discovery: Found device Volumio Feb 18 03:44:35 volumio volumio[9368]: info: CoreCommandRouter::volumioGetState Feb 18 03:44:36 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:36 volumio volumio[9368]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 03:44:36 volumio volumio[9368]: info: Discovery: Found device Volumio Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::volumioGetState Feb 18 03:44:36 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:36 volumio volumio[9368]: info: MPD Permissions set Feb 18 03:44:36 volumio volumio[9368]: info: MPD Permissions set Feb 18 03:44:36 volumio volumio[9368]: info: Upmpdcli Daemon Started Feb 18 03:44:36 volumio volumio[9368]: info: Spotify config file written Feb 18 03:44:36 volumio volumio[9368]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio sudo[9602]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 03:44:36 volumio sudo[9602]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 03:44:36 volumio volumio[9368]: info: No need to fix Spotify hosts Feb 18 03:44:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:36 volumio go-librespot[9609]: go-librespot daemon starting... Feb 18 03:44:36 volumio sudo[9602]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:36 volumio go-librespot[9615]: time="2026-02-18T03:44:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:36 volumio go-librespot[9615]: time="2026-02-18T03:44:36+07:00" level=debug msg="app state loaded" Feb 18 03:44:36 volumio go-librespot[9615]: time="2026-02-18T03:44:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:37 volumio go-librespot[9615]: time="2026-02-18T03:44:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 03:44:37 volumio go-librespot[9615]: time="2026-02-18T03:44:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 03:44:37 volumio go-librespot[9615]: time="2026-02-18T03:44:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 03:44:37 volumio go-librespot[9615]: time="2026-02-18T03:44:37+07:00" level=info msg="zeroconf server listening on port 36605" Feb 18 03:44:37 volumio go-librespot[9615]: time="2026-02-18T03:44:37+07:00" level=debug msg="obtained new client token: AAB9A55qgNWTzArzmcwsdPzLG5WVN5e6wpZBkCgw8AX2OW5sRgK67v2bk2EBlcY46qMJbx7aFMH2Gz8VDd5XM2N/0VC/IlcIuGI16iu+TCKKX0C7yZpeFVvHfPmJPr8RuJt/yC+XagZEtMFe2ItrzdqWnGse+5drF58lAPjsODGniqySzzGrAug7A1g8FmOJgAhN5y/sn0MxrqOI890MQrQxBNdCULMcxzZZzlGAW+dclFaA7fmJ/v38bQ==" Feb 18 03:44:37 volumio go-librespot[9615]: time="2026-02-18T03:44:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:37 volumio volumio[9368]: info: Volumio called home Feb 18 03:44:37 volumio volumio[9368]: info: Starting Shairport Sync Feb 18 03:44:38 volumio go-librespot[9615]: time="2026-02-18T03:44:38+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:38 volumio go-librespot[9615]: time="2026-02-18T03:44:38+07:00" level=debug msg="completed challenge" Feb 18 03:44:38 volumio volumio[9368]: info: Starting Shairport Sync Feb 18 03:44:38 volumio volumio[9368]: info: Starting Shairport Sync Feb 18 03:44:38 volumio go-librespot[9615]: time="2026-02-18T03:44:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:38 volumio sudo[9644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 03:44:38 volumio sudo[9644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:38 volumio sudo[9643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 03:44:38 volumio sudo[9643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 03:44:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 03:44:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 03:44:38 volumio systemd[1]: shairport-sync.service: Consumed 2.383s CPU time. Feb 18 03:44:38 volumio sudo[9647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 03:44:38 volumio sudo[9647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 03:44:38 volumio sudo[9644]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 03:44:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 03:44:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 03:44:38 volumio volumio[9368]: info: Shairport-Sync Started Feb 18 03:44:38 volumio volumio[9368]: Error adding Membership: Error: addMembership EINVAL Feb 18 03:44:38 volumio volumio[9368]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 03:44:38 volumio volumio[9368]: SPOTIFY: BQCDGjYRGfbfyWHkgvt0y3HhL_kLog6vdjycNmLAe9DfgLUWCifDHSDq_aTbZ46r2pbtfW2nL5JIlIayqz__dOodlWiO2X70CBbFhaKyFYKAgYugcHawwqQ3JTf7otR6-mqcQot1cvwDmvyX6GidU2E61axHMkgRYzUSnZo02TkkuPNkv2MXtLE50yd7HOeUaANQyCF_mWfsfDfkgJDKC47w9F1AMK2UhGnxo0b50l2SasarTVtgGR9PDPnQOn1HTPXnzpkxY4hr6OMybzlgN117Ey1hwAv-dFuXZFVMDJ4_O46KPfQHkwmI Feb 18 03:44:38 volumio volumio[9368]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 03:44:38 volumio volumio[9368]: info: New Spotify access token = BQCDGjYRGfbfyWHkgvt0y3HhL_kLog6vdjycNmLAe9DfgLUWCifDHSDq_aTbZ46r2pbtfW2nL5JIlIayqz__dOodlWiO2X70CBbFhaKyFYKAgYugcHawwqQ3JTf7otR6-mqcQot1cvwDmvyX6GidU2E61axHMkgRYzUSnZo02TkkuPNkv2MXtLE50yd7HOeUaANQyCF_mWfsfDfkgJDKC47w9F1AMK2UhGnxo0b50l2SasarTVtgGR9PDPnQOn1HTPXnzpkxY4hr6OMybzlgN117Ey1hwAv-dFuXZFVMDJ4_O46KPfQHkwmI Feb 18 03:44:38 volumio volumio[9368]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 03:44:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 03:44:38 volumio sudo[9643]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:38 volumio sudo[9647]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:38 volumio volumio[9368]: info: CoreCommandRouter::volumioGetState Feb 18 03:44:38 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:38 volumio volumio[9368]: info: Shairport-Sync Started Feb 18 03:44:38 volumio volumio[9368]: info: Shairport-Sync Started Feb 18 03:44:39 volumio volumio[9368]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 03:44:39 volumio volumio[9368]: info: Spotify Successfully logged in Feb 18 03:44:39 volumio volumio[9368]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 03:44:39 volumio volumio[9368]: info: [1771361079087] CoreMusicLibrary::Adding element Spotify Feb 18 03:44:39 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 03:44:39 volumio volumio[9368]: Cannot find translation for source YouTube Music Feb 18 03:44:39 volumio volumio[9368]: Cannot find translation for source Spotify Feb 18 03:44:39 volumio volumio[9368]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 03:44:39 volumio volumio[9368]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 03:44:39 volumio volumio[9368]: info: VolumeController:: Volume=100 Mute =false Feb 18 03:44:39 volumio volumio[9368]: info: CoreCommandRouter::volumioGetState Feb 18 03:44:39 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:39 volumio volumio[9368]: info: CoreStateMachine::pushState Feb 18 03:44:39 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:39 volumio volumio[9368]: info: CoreCommandRouter::volumioPushState Feb 18 03:44:40 volumio volumio[9368]: info: go-librespot daemon successfully initialized Feb 18 03:44:41 volumio mpd[9594]: 2026-02-18T03:44:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 03:44:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 18 03:44:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 03:44:41 volumio sudo[9556]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:41 volumio sudo[9545]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:41 volumio go-librespot[9702]: go-librespot daemon starting... Feb 18 03:44:41 volumio go-librespot[9703]: time="2026-02-18T03:44:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:41 volumio go-librespot[9703]: time="2026-02-18T03:44:41+07:00" level=debug msg="app state loaded" Feb 18 03:44:41 volumio go-librespot[9703]: time="2026-02-18T03:44:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:41 volumio volumio[9368]: error: MPD error: The expression evaluated to a falsy value: Feb 18 03:44:41 volumio volumio[9368]: assert.ok(self.idling) Feb 18 03:44:41 volumio volumio[9368]: error: The expression evaluated to a falsy value: Feb 18 03:44:41 volumio volumio[9368]: assert.ok(self.idling) Feb 18 03:44:41 volumio volumio[9368]: info: MPD running with PID9594 Feb 18 03:44:41 volumio volumio[9368]: ,establishing connection Feb 18 03:44:41 volumio volumio[9368]: error: updateQueue error: null Feb 18 03:44:41 volumio volumio[9368]: info: Completed starting Core Plugins Feb 18 03:44:41 volumio volumio[9368]: info: ------------------------------------------- Feb 18 03:44:41 volumio volumio[9368]: info: ----- MyVolumio plugins startup ---- Feb 18 03:44:41 volumio volumio[9368]: info: ------------------------------------------- Feb 18 03:44:41 volumio volumio[9368]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 03:44:41 volumio volumio[9368]: error: updateQueue error: null Feb 18 03:44:41 volumio go-librespot[9703]: time="2026-02-18T03:44:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:44:41 volumio go-librespot[9703]: time="2026-02-18T03:44:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:44:41 volumio go-librespot[9703]: time="2026-02-18T03:44:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:44:41 volumio go-librespot[9703]: time="2026-02-18T03:44:41+07:00" level=info msg="zeroconf server listening on port 33971" Feb 18 03:44:42 volumio go-librespot[9703]: time="2026-02-18T03:44:42+07:00" level=debug msg="obtained new client token: AAC9/VmRrhcP+qBoxAgoYkWNnd974N3cqoMiBZZUrxQXD91OstRXkorN/27um9DC43eQDrnz1VBfPxOgnwct09C4GvAcCRbwdlmhi5kUtXYZk09JAoAQJElaAMrL7bqhCTzBXo16skRNWI1aJAvvn2S5c71avOS8zNBcpvii6Q+tAsYxpteopqgaveZNVCuGhCpaYQdjkq+7xbRIE5U6IkFljf1YA9MFBEPT5a6dmr1HOAnNWQhJkGc=" Feb 18 03:44:42 volumio go-librespot[9703]: time="2026-02-18T03:44:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:42 volumio go-librespot[9703]: time="2026-02-18T03:44:42+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:42 volumio go-librespot[9703]: time="2026-02-18T03:44:42+07:00" level=debug msg="completed challenge" Feb 18 03:44:42 volumio go-librespot[9703]: time="2026-02-18T03:44:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:43 volumio volumio[9368]: info: Initializing connection to go-librespot Websocket Feb 18 03:44:43 volumio volumio[9368]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:44:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 18 03:44:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:45 volumio go-librespot[9712]: go-librespot daemon starting... Feb 18 03:44:45 volumio go-librespot[9713]: time="2026-02-18T03:44:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:45 volumio go-librespot[9713]: time="2026-02-18T03:44:45+07:00" level=debug msg="app state loaded" Feb 18 03:44:45 volumio go-librespot[9713]: time="2026-02-18T03:44:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:46 volumio go-librespot[9713]: time="2026-02-18T03:44:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:44:46 volumio go-librespot[9713]: time="2026-02-18T03:44:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:44:46 volumio go-librespot[9713]: time="2026-02-18T03:44:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:44:46 volumio go-librespot[9713]: time="2026-02-18T03:44:46+07:00" level=info msg="zeroconf server listening on port 42221" Feb 18 03:44:46 volumio volumio[9368]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 03:44:46 volumio go-librespot[9713]: time="2026-02-18T03:44:46+07:00" level=debug msg="obtained new client token: AADflk9rMvIbCXJXM9H4cn5Jv698c21jMWw4mJVyaTJxitQ9Nb8URF5F+botlZdmK/V/g1/mqZbuA/PrkRBUcjRI89vDskFnvfjcssEPNjH7vPDfDC2ektJdIocMHAfnJrDYlWDeKRGGIYPxzEUOpmqII09b5ohBLGESM+seXofAJNpHhn44DRFkkt7KyNVTiXSo9dNrgJhgGFmZsvx1rNGutye0M46zJWQuae6kYFdSYneFOvZIaNY6jg==" Feb 18 03:44:46 volumio go-librespot[9713]: time="2026-02-18T03:44:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:46 volumio go-librespot[9713]: time="2026-02-18T03:44:46+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:46 volumio go-librespot[9713]: time="2026-02-18T03:44:46+07:00" level=debug msg="completed challenge" Feb 18 03:44:46 volumio go-librespot[9713]: time="2026-02-18T03:44:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:46 volumio volumio[9368]: info: Initializing connection to go-librespot Websocket Feb 18 03:44:46 volumio volumio[9368]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 03:44:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 18 03:44:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:49 volumio go-librespot[9721]: go-librespot daemon starting... Feb 18 03:44:49 volumio go-librespot[9722]: time="2026-02-18T03:44:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:49 volumio go-librespot[9722]: time="2026-02-18T03:44:49+07:00" level=debug msg="app state loaded" Feb 18 03:44:49 volumio go-librespot[9722]: time="2026-02-18T03:44:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:49 volumio volumio[9368]: info: Initializing connection to go-librespot Websocket Feb 18 03:44:49 volumio go-librespot[9722]: time="2026-02-18T03:44:49+07:00" level=debug msg="new websocket client" Feb 18 03:44:49 volumio volumio[9368]: info: Connection to go-librespot Websocket established Feb 18 03:44:50 volumio go-librespot[9722]: time="2026-02-18T03:44:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:44:50 volumio go-librespot[9722]: time="2026-02-18T03:44:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:44:50 volumio go-librespot[9722]: time="2026-02-18T03:44:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 03:44:50 volumio volumio[9368]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 03:44:50 volumio go-librespot[9722]: time="2026-02-18T03:44:50+07:00" level=info msg="zeroconf server listening on port 42063" Feb 18 03:44:50 volumio volumio[9368]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 03:44:50 volumio volumio[9368]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 03:44:50 volumio volumio[9368]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 03:44:50 volumio volumio[9368]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 03:44:50 volumio volumio[9368]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 03:44:50 volumio volumio[9368]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 03:44:50 volumio volumio[9368]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 03:44:50 volumio go-librespot[9722]: time="2026-02-18T03:44:50+07:00" level=debug msg="obtained new client token: AADzgylolUa+M4leLjNHAsQSw9NurXXoeNbvyfUVSqSHuyx/s9kQTvHJVV9RqP8tZyK+cvfJdqpJwcwN1sv9u7E7C4cv0keL59IDeck+/xZtA2gnSzMWzPgGs2FxWBKGmLW+CIslZ2wcO5I9NsSvNRE/0MLzZ4AxOva0aWYLWwhnpAk5sjvduIezfGqMqBfTu0TmglskGa5SF0jh172P2JI9FSrgxSEg5S6Al7he9YJZZOh3lYo0b4flRg==" Feb 18 03:44:50 volumio go-librespot[9722]: time="2026-02-18T03:44:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:50 volumio go-librespot[9722]: time="2026-02-18T03:44:50+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:50 volumio go-librespot[9722]: time="2026-02-18T03:44:50+07:00" level=debug msg="completed challenge" Feb 18 03:44:50 volumio go-librespot[9722]: time="2026-02-18T03:44:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:52 volumio volumio[9368]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 03:44:52 volumio volumio[9368]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 03:44:52 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:52 volumio volumio[9368]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 03:44:52 volumio volumio[9368]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 03:44:52 volumio volumio[9368]: info: MyVolumio login type: Token Feb 18 03:44:52 volumio volumio[9368]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 03:44:52 volumio volumio[9368]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 03:44:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 18 03:44:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:54 volumio volumio[9368]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 03:44:54 volumio volumio[9368]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 03:44:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 03:44:54 volumio volumio[9368]: info: Streaming services startup Feb 18 03:44:54 volumio volumio[9368]: info: Starting Streaming Daemon Feb 18 03:44:54 volumio go-librespot[9743]: go-librespot daemon starting... Feb 18 03:44:54 volumio sudo[9746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 03:44:54 volumio go-librespot[9744]: time="2026-02-18T03:44:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 03:44:54 volumio go-librespot[9744]: time="2026-02-18T03:44:54+07:00" level=debug msg="app state loaded" Feb 18 03:44:54 volumio go-librespot[9744]: time="2026-02-18T03:44:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 03:44:54 volumio sudo[9746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 03:44:54 volumio volumio[9368]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 03:44:54 volumio sudo[9746]: pam_unix(sudo:session): session closed for user root Feb 18 03:44:54 volumio volumio[9368]: info: Getting Spotify volume Feb 18 03:44:54 volumio volumio[9368]: info: Connection to go-librespot Websocket closed Feb 18 03:44:54 volumio volumio[9368]: error: Cannot start Volumio Streaming Daemon Feb 18 03:44:54 volumio volumio[9368]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 03:44:54 volumio volumio[9368]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 03:44:54 volumio volumio[9368]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 18 03:44:54 volumio volumio[9368]: info: CoreCommandRouter::volumioGetState Feb 18 03:44:54 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:54 volumio volumio[9368]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 03:44:54 volumio volumio[9368]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 03:44:54 volumio volumio[9368]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 03:44:54 volumio volumio[9368]: info: Aligning Spotify Volume to Volumio Volume Feb 18 03:44:54 volumio volumio[9368]: info: CoreCommandRouter::volumioGetState Feb 18 03:44:54 volumio volumio[9368]: info: CorePlayQueue::getTrack 0 Feb 18 03:44:54 volumio volumio[9368]: info: Setting Spotify Volume from Volumio: 100 Feb 18 03:44:54 volumio go-librespot[9744]: time="2026-02-18T03:44:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 03:44:54 volumio go-librespot[9744]: time="2026-02-18T03:44:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 03:44:54 volumio go-librespot[9744]: time="2026-02-18T03:44:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 03:44:54 volumio go-librespot[9744]: time="2026-02-18T03:44:54+07:00" level=info msg="zeroconf server listening on port 43963" Feb 18 03:44:55 volumio go-librespot[9744]: time="2026-02-18T03:44:55+07:00" level=debug msg="obtained new client token: AADz985DCKngo/SvOzr/j4ekTWXHj05s8+xybg3jbYMkQNw6+KdwlqKcs1UqEIphNh/D7n/Xy9DgHnl3McuL24DHYD2Y4P/J7uysllDqWZMvISgApePsWOZsEVD3I24kmVdnIg6Vx/n6XeRKugdonShm9bSmEBDS/5mWwzPGDwdlg4ynyS2uyR7ZNwrZZ59aUKUNrqy67vBaWaz3eLylbPkMM1V8hZSzmfdFqwJnVAiCkYaVhR8zVbWBwg==" Feb 18 03:44:55 volumio go-librespot[9744]: time="2026-02-18T03:44:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 03:44:55 volumio go-librespot[9744]: time="2026-02-18T03:44:55+07:00" level=debug msg="completed keyexchange" Feb 18 03:44:55 volumio go-librespot[9744]: time="2026-02-18T03:44:55+07:00" level=debug msg="completed challenge" Feb 18 03:44:55 volumio go-librespot[9744]: time="2026-02-18T03:44:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 03:44:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 03:44:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 03:44:55 volumio volumio[9368]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 03:44:55 volumio volumio[9368]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 03:44:55 volumio volumio[9368]: Error: socket hang up Feb 18 03:44:55 volumio volumio[9368]: at connResetException (node:internal/errors:720:14) Feb 18 03:44:55 volumio volumio[9368]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 03:44:55 volumio volumio[9368]: at Socket.emit (node:events:526:35) Feb 18 03:44:55 volumio volumio[9368]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 03:44:55 volumio volumio[9368]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 03:44:55 volumio volumio[9368]: code: 'ECONNRESET', Feb 18 03:44:55 volumio volumio[9368]: response: undefined Feb 18 03:44:55 volumio volumio[9368]: } Feb 18 03:44:55 volumio volumio[9368]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 03:44:56 volumio sudo[9772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 03:43' Feb 18 03:44:56 volumio sudo[9772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"