Feb 19 01:24:00 volumio volumio[19606]: info: Applying required configuration parameters for plugin RoonBridge
Feb 19 01:24:00 volumio volumio[19606]: info: Loading i18n strings for locale en
Feb 19 01:24:00 volumio volumio[19606]: Updating browse sources language
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::initPlayerControls
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 19 01:24:00 volumio volumio[19606]: Express server listening on port 3000
Feb 19 01:24:00 volumio volumio[19606]: [Metrics] WebUI: 15s 951.68ms
Feb 19 01:24:00 volumio volumio[19719]: Forking 3 albumart workers
Feb 19 01:24:00 volumio volumio[19606]: info: CoreStateMachine::resetVolumioState
Feb 19 01:24:00 volumio volumio[19606]: info: CoreStateMachine::getcurrentVolume
Feb 19 01:24:00 volumio volumio[19606]: info: CoreCommandRouter::volumioRetrievevolume
Feb 19 01:24:00 volumio sudo[19753]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 19 01:24:00 volumio sudo[19753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:00 volumio sudo[19753]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:00 volumio sudo[19757]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 19 01:24:00 volumio sudo[19757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:00 volumio sudo[19757]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:00 volumio volumio[19606]: info: Volumio Network Manager: Network status updated: 1
Feb 19 01:24:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Feb 19 01:24:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:01 volumio volumio[19606]: info: VolumeController:: Volume=100 Mute =false
Feb 19 01:24:01 volumio volumio[19606]: info: CoreStateMachine::pushState
Feb 19 01:24:01 volumio volumio[19606]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:01 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 19 01:24:01 volumio volumio[19606]: info: CoreCommandRouter::volumioPushState
Feb 19 01:24:01 volumio volumio[19606]: info: CoreStateMachine::updateTrackBlock
Feb 19 01:24:01 volumio volumio[19606]: info: CorePlayQueue::getTrackBlock
Feb 19 01:24:01 volumio volumio[19606]: info: CoreCommandRouter::volumioRetrievevolume
Feb 19 01:24:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:01 volumio go-librespot[19770]: go-librespot daemon starting...
Feb 19 01:24:01 volumio go-librespot[19771]: time="2026-02-19T01:24:01+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:01 volumio go-librespot[19771]: time="2026-02-19T01:24:01+07:00" level=debug msg="app state loaded"
Feb 19 01:24:01 volumio go-librespot[19771]: time="2026-02-19T01:24:01+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:01 volumio volumio-remote-updater[25144]: [2026-02-19 01:24:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771439039 101
Feb 19 01:24:01 volumio volumio[19606]: 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 19 01:24:01 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:01 volumio volumio[19606]: info: Reloading queue from file
Feb 19 01:24:01 volumio volumio[19606]: info: CoreStateMachine::setRepeat null single undefined
Feb 19 01:24:01 volumio volumio[19606]: info: CoreStateMachine::pushState
Feb 19 01:24:01 volumio volumio[19606]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:01 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 19 01:24:01 volumio volumio[19606]: info: CoreCommandRouter::volumioPushState
Feb 19 01:24:01 volumio volumio[19606]: info: CoreStateMachine::setRandom null
Feb 19 01:24:01 volumio volumio[19606]: info: CoreStateMachine::pushState
Feb 19 01:24:01 volumio volumio[19606]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:01 volumio volumio[19606]: info: CoreCommandRouter::volumioPushState
Feb 19 01:24:01 volumio volumio[19606]: info: Setting Device type: Raspberry PI
Feb 19 01:24:01 volumio volumio[19606]: info: Completed loading Core Plugins
Feb 19 01:24:01 volumio volumio[19606]: info: Preparing to generate the ALSA configuration file
Feb 19 01:24:01 volumio volumio[19606]: info: VolumeController:: Volume=100 Mute =false
Feb 19 01:24:01 volumio volumio[19606]: info: CoreStateMachine::pushState
Feb 19 01:24:01 volumio volumio[19606]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:01 volumio volumio[19606]: info: CoreCommandRouter::volumioPushState
Feb 19 01:24:01 volumio volumio[19606]: info: Asound.conf file unchanged, so no further update is needed
Feb 19 01:24:01 volumio volumio[19606]: info: Output device has changed, restarting MPD
Feb 19 01:24:01 volumio go-librespot[19771]: time="2026-02-19T01:24: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 19 01:24:01 volumio go-librespot[19771]: time="2026-02-19T01:24:01+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 19 01:24:01 volumio go-librespot[19771]: time="2026-02-19T01:24:01+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 19 01:24:01 volumio go-librespot[19771]: time="2026-02-19T01:24:01+07:00" level=info msg="zeroconf server listening on port 40149"
Feb 19 01:24:01 volumio sudo[19787]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 19 01:24:01 volumio volumio[19606]: info: Output device has changed, restarting Shairport Sync
Feb 19 01:24:01 volumio sudo[19787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:01 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:01 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:01 volumio sudo[19789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 19 01:24:01 volumio sudo[19789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:02 volumio sudo[19791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 19 01:24:02 volumio sudo[19791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:02 volumio sudo[19789]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:02 volumio volumio[19606]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 19 01:24:02 volumio volumio[19606]: info: ___________ START PLUGINS ___________
Feb 19 01:24:02 volumio volumio[19606]: info: ControllerMpd::onStart: Initializing MPD
Feb 19 01:24:02 volumio sudo[19787]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:02 volumio go-librespot[19771]: time="2026-02-19T01:24:02+07:00" level=debug msg="obtained new client token: AAB4pNDM4yvH58j+/Be3JK3lNhSkmfiX329QraZ+cs4deVcUHCxSmNBBXS8T0z6v9PCUN+tKdBWJ9GlANs7Rl9dezA/N7fRIG84xh2INQjb4403WRiBQso5EbWimhMTFJ9ZC5B9/z5tC+X4uFIW5H8sTCTPM1O1O5JSySPHzQl8h7Fhr54PmUnh1g9WzHha7d+TIJ2aWOD1acSoczFjLVe0M6xZ+GeXY4EpYyUf0LzqW77NTEsmB3pM="
Feb 19 01:24:02 volumio volumio[19606]: info: Creating MPD Configuration file
Feb 19 01:24:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:24:02 volumio volumio[19606]: info: [1771439042185] CoreMusicLibrary::Adding element Media Servers
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:02 volumio volumio[19606]: info: UPNP Browser: Client initialized successfully
Feb 19 01:24:02 volumio go-librespot[19771]: time="2026-02-19T01:24:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:02 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 19 01:24:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 19 01:24:02 volumio systemd[1]: mpd.service: Consumed 7.217s CPU time.
Feb 19 01:24:02 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 19 01:24:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 19 01:24:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 19 01:24:02 volumio sudo[19800]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 19 01:24:02 volumio sudo[19800]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:02 volumio go-librespot[19771]: time="2026-02-19T01:24:02+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:02 volumio go-librespot[19771]: time="2026-02-19T01:24:02+07:00" level=debug msg="completed challenge"
Feb 19 01:24:02 volumio sudo[19802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 19 01:24:02 volumio sudo[19800]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:02 volumio sudo[19802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:02 volumio volumio[19606]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 19 01:24:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 19 01:24:02 volumio go-librespot[19771]: time="2026-02-19T01:24: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 19 01:24:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:02 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 19 01:24:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 19 01:24:02 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 19 01:24:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 19 01:24:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 19 01:24:02 volumio volumio[19606]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:24:02 volumio volumio[19606]: info: [1771439042603] CoreMusicLibrary::Adding element Last_100
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:24:02 volumio volumio[19606]: info: [1771439042632] CoreMusicLibrary::Adding element Webradio
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 19 01:24:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 19 01:24:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 19 01:24:02 volumio volumio[19606]: info: Initializing BBC Radios
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:02 volumio volumio[19606]: info: Creating Spotify config file
Feb 19 01:24:02 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:03 volumio sudo[19816]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 19 01:24:03 volumio sudo[19816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 19 01:24:03 volumio sudo[19816]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:03 volumio volumio[19732]: Starting albumart workers
Feb 19 01:24:03 volumio volumio[19733]: Starting albumart workers
Feb 19 01:24:04 volumio volumio[19606]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:24:04 volumio volumio[19606]: info: [1771439044230] CoreMusicLibrary::Adding element YouTube Music
Feb 19 01:24:04 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:04 volumio volumio[19606]: Cannot find translation for source YouTube Music
Feb 19 01:24:04 volumio volumio[19606]: info: Volumio Calling Home
Feb 19 01:24:04 volumio sudo[19834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 19 01:24:04 volumio sudo[19834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:04 volumio volumio[19735]: Starting albumart workers
Feb 19 01:24:04 volumio sudo[19834]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:05 volumio volumio[19606]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 19 01:24:05 volumio volumio[19606]: info: Discovery: Found device Volumio
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::volumioGetState
Feb 19 01:24:05 volumio volumio[19606]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:05 volumio volumio[19606]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7
Feb 19 01:24:05 volumio volumio[19606]: info: Discovery: Found device Volumio
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::volumioGetState
Feb 19 01:24:05 volumio volumio[19606]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:05 volumio volumio[19606]: info: MPD Permissions set
Feb 19 01:24:05 volumio volumio[19606]: info: MPD Permissions set
Feb 19 01:24:05 volumio volumio[19606]: info: Upmpdcli Daemon Started
Feb 19 01:24:05 volumio volumio[19606]: info: Spotify config file written
Feb 19 01:24:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Feb 19 01:24:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:05 volumio volumio[19606]: 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 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:05 volumio go-librespot[19848]: go-librespot daemon starting...
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio sudo[19847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 19 01:24:05 volumio sudo[19847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio go-librespot[19850]: time="2026-02-19T01:24:05+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:05 volumio go-librespot[19850]: time="2026-02-19T01:24:05+07:00" level=debug msg="app state loaded"
Feb 19 01:24:05 volumio go-librespot[19850]: time="2026-02-19T01:24:05+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:05 volumio volumio[19606]: info: No need to fix Spotify hosts
Feb 19 01:24:05 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 19 01:24:05 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 19 01:24:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:05 volumio go-librespot[19872]: go-librespot daemon starting...
Feb 19 01:24:06 volumio sudo[19847]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:06 volumio go-librespot[19873]: time="2026-02-19T01:24:06+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:06 volumio go-librespot[19873]: time="2026-02-19T01:24:06+07:00" level=debug msg="app state loaded"
Feb 19 01:24:06 volumio go-librespot[19873]: time="2026-02-19T01:24:06+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:06 volumio go-librespot[19873]: time="2026-02-19T01:24: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 19 01:24:06 volumio go-librespot[19873]: time="2026-02-19T01:24:06+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 19 01:24:06 volumio go-librespot[19873]: time="2026-02-19T01:24:06+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 19 01:24:06 volumio go-librespot[19873]: time="2026-02-19T01:24:06+07:00" level=info msg="zeroconf server listening on port 42973"
Feb 19 01:24:06 volumio volumio[19606]: info: Volumio called home
Feb 19 01:24:06 volumio volumio[19606]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 19 01:24:06 volumio volumio[19606]: SPOTIFY: BQASFPkaT8jofL0627OO_t-1JY4OWeIzlQ2obLZGJ-fR9H9ijP1k16Pu7g4Lvw0ghgYLn8Tw7LyQOLwnI9v4NrBzT49HeQDVKGECxGoBZhhArZAZ6rgQGHNvWWUl9NQQNQ-ehPb_tj9QlciUqr4ygTg0Q1H5ZSutdCD9k7oFljCIt9gjGoeHJglEx9ckWGcclqa-IBjUWAQEcdllqQ1mUhHXByX9s97flDZl-0x53R8WLOyoVM43EzCBUsvYH47elSiP6k5GK_j01oF4d4-bceBTlkoTAbJhP6ikvqfKn342MZmsGbhNInvG
Feb 19 01:24:06 volumio volumio[19606]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 19 01:24:06 volumio volumio[19606]: info: New Spotify access token = BQASFPkaT8jofL0627OO_t-1JY4OWeIzlQ2obLZGJ-fR9H9ijP1k16Pu7g4Lvw0ghgYLn8Tw7LyQOLwnI9v4NrBzT49HeQDVKGECxGoBZhhArZAZ6rgQGHNvWWUl9NQQNQ-ehPb_tj9QlciUqr4ygTg0Q1H5ZSutdCD9k7oFljCIt9gjGoeHJglEx9ckWGcclqa-IBjUWAQEcdllqQ1mUhHXByX9s97flDZl-0x53R8WLOyoVM43EzCBUsvYH47elSiP6k5GK_j01oF4d4-bceBTlkoTAbJhP6ikvqfKn342MZmsGbhNInvG
Feb 19 01:24:06 volumio volumio[19606]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 19 01:24:06 volumio volumio[19606]: info: Starting Shairport Sync
Feb 19 01:24:06 volumio go-librespot[19873]: time="2026-02-19T01:24:06+07:00" level=debug msg="obtained new client token: AAC8NyuIo7ORr1nEB+OVre73fa8EwuKYc3F/t1gjJmT6bJXDtyfMNCyEFK6kKxFsbNoU3X5uigqEfToDWacDBIvtESol3JOlvDi5q3gTX7lVwwdoHXjFAR0V4Jm6x+iYWLfU+oYgyGBBg3lXWu3WmUsEt6p90Et4hxEK0YX25MKeJK2WY9W3Z34/m5fwT/4jz3tYBOym+9fn7E6guKPQI+TEj3/0GTIpd2Q7b7EjsmAIeBzNMJaOa7rNVg=="
Feb 19 01:24:06 volumio volumio[19606]: info: Starting Shairport Sync
Feb 19 01:24:06 volumio volumio[19606]: info: Starting Shairport Sync
Feb 19 01:24:07 volumio sudo[19887]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 19 01:24:07 volumio sudo[19887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:07 volumio sudo[19891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 19 01:24:07 volumio sudo[19889]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 19 01:24:07 volumio sudo[19889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:07 volumio sudo[19891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:07 volumio go-librespot[19873]: time="2026-02-19T01:24:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:07 volumio go-librespot[19873]: time="2026-02-19T01:24:07+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:07 volumio go-librespot[19873]: time="2026-02-19T01:24:07+07:00" level=debug msg="completed challenge"
Feb 19 01:24:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 19 01:24:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 19 01:24:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 19 01:24:07 volumio systemd[1]: shairport-sync.service: Consumed 2.289s CPU time.
Feb 19 01:24:07 volumio go-librespot[19873]: time="2026-02-19T01:24:07+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 19 01:24:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 19 01:24:07 volumio sudo[19891]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:07 volumio sudo[19889]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:07 volumio sudo[19887]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:07 volumio volumio[19606]: info: CoreCommandRouter::volumioGetState
Feb 19 01:24:07 volumio volumio[19606]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:07 volumio volumio[19606]: info: Shairport-Sync Started
Feb 19 01:24:07 volumio volumio[19606]: Error adding Membership: Error: addMembership EINVAL
Feb 19 01:24:07 volumio volumio[19606]: info: Shairport-Sync Started
Feb 19 01:24:07 volumio volumio[19606]: info: Shairport-Sync Started
Feb 19 01:24:07 volumio volumio[19606]: 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 19 01:24:07 volumio volumio[19606]: info: Spotify Successfully logged in
Feb 19 01:24:07 volumio volumio[19606]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:24:07 volumio volumio[19606]: info: [1771439047767] CoreMusicLibrary::Adding element Spotify
Feb 19 01:24:07 volumio volumio[19606]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:07 volumio volumio[19606]: Cannot find translation for source YouTube Music
Feb 19 01:24:07 volumio volumio[19606]: Cannot find translation for source Spotify
Feb 19 01:24:08 volumio volumio[19606]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 19 01:24:08 volumio volumio[19606]: info: CoreCommandRouter::volumioRetrievevolume
Feb 19 01:24:08 volumio volumio[19606]: info: VolumeController:: Volume=100 Mute =false
Feb 19 01:24:08 volumio volumio[19606]: info: CoreCommandRouter::volumioGetState
Feb 19 01:24:08 volumio volumio[19606]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:08 volumio volumio[19606]: info: CoreStateMachine::pushState
Feb 19 01:24:08 volumio volumio[19606]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:08 volumio volumio[19606]: info: CoreCommandRouter::volumioPushState
Feb 19 01:24:09 volumio volumio[19606]: info: go-librespot daemon successfully initialized
Feb 19 01:24:10 volumio mpd[19831]: 2026-02-19T01:24:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 19 01:24:10 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 19 01:24:10 volumio sudo[19802]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:10 volumio sudo[19791]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:10 volumio volumio[19606]: error: MPD error: The expression evaluated to a falsy value:
Feb 19 01:24:10 volumio volumio[19606]: assert.ok(self.idling)
Feb 19 01:24:10 volumio volumio[19606]: error: The expression evaluated to a falsy value:
Feb 19 01:24:10 volumio volumio[19606]: assert.ok(self.idling)
Feb 19 01:24:10 volumio volumio[19606]: error: updateQueue error: null
Feb 19 01:24:10 volumio volumio[19606]: info: MPD running with PID19831
Feb 19 01:24:10 volumio volumio[19606]: ,establishing connection
Feb 19 01:24:10 volumio volumio[19606]: info: Completed starting Core Plugins
Feb 19 01:24:10 volumio volumio[19606]: info: -------------------------------------------
Feb 19 01:24:10 volumio volumio[19606]: info: ----- MyVolumio plugins startup ----
Feb 19 01:24:10 volumio volumio[19606]: info: -------------------------------------------
Feb 19 01:24:10 volumio volumio[19606]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 19 01:24:10 volumio volumio[19606]: error: updateQueue error: null
Feb 19 01:24:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 19 01:24:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:10 volumio go-librespot[19932]: go-librespot daemon starting...
Feb 19 01:24:10 volumio go-librespot[19933]: time="2026-02-19T01:24:10+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:10 volumio go-librespot[19933]: time="2026-02-19T01:24:10+07:00" level=debug msg="app state loaded"
Feb 19 01:24:10 volumio go-librespot[19933]: time="2026-02-19T01:24:10+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:11 volumio go-librespot[19933]: time="2026-02-19T01:24: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 19 01:24:11 volumio go-librespot[19933]: time="2026-02-19T01:24: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 19 01:24:11 volumio go-librespot[19933]: time="2026-02-19T01:24: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 19 01:24:11 volumio go-librespot[19933]: time="2026-02-19T01:24:11+07:00" level=info msg="zeroconf server listening on port 45789"
Feb 19 01:24:11 volumio go-librespot[19933]: time="2026-02-19T01:24:11+07:00" level=debug msg="obtained new client token: AAAUASX6QWxRVrcw0ttTudORnkoZWTlPF0Q8ZciigmQhTxKyfqE+52f6J8J/TYhjf85mIGk5nXTZymm0yTzBWZO/12VchE3k4hsgMy2XMI7uB9ECPsFozPcQrSuNVpkHaNfJ+2e+F2gqgKDh5rgXHEh0NALBTfkRgIRrKN2NbkOlzPKfF/QEfDKm8x7OstoPr6mNATNuStZ66MAWWiYTgKAr105BHjCeOYhYhrE2PkHXmJKHU4tY1egQhg=="
Feb 19 01:24:11 volumio go-librespot[19933]: time="2026-02-19T01:24:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:11 volumio go-librespot[19933]: time="2026-02-19T01:24:11+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:11 volumio go-librespot[19933]: time="2026-02-19T01:24:11+07:00" level=debug msg="completed challenge"
Feb 19 01:24:11 volumio go-librespot[19933]: time="2026-02-19T01:24:11+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 19 01:24:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:12 volumio volumio[19606]: info: Initializing connection to go-librespot Websocket
Feb 19 01:24:12 volumio volumio[19606]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 19 01:24:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 19 01:24:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:14 volumio go-librespot[19943]: go-librespot daemon starting...
Feb 19 01:24:14 volumio go-librespot[19944]: time="2026-02-19T01:24:14+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:14 volumio go-librespot[19944]: time="2026-02-19T01:24:14+07:00" level=debug msg="app state loaded"
Feb 19 01:24:14 volumio go-librespot[19944]: time="2026-02-19T01:24:14+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:15 volumio volumio[19606]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Feb 19 01:24:15 volumio go-librespot[19944]: time="2026-02-19T01:24:15+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 19 01:24:15 volumio go-librespot[19944]: time="2026-02-19T01:24:15+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 19 01:24:15 volumio go-librespot[19944]: time="2026-02-19T01:24:15+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 19 01:24:15 volumio go-librespot[19944]: time="2026-02-19T01:24:15+07:00" level=info msg="zeroconf server listening on port 41979"
Feb 19 01:24:15 volumio go-librespot[19944]: time="2026-02-19T01:24:15+07:00" level=debug msg="obtained new client token: AACe4rBMUGdY0wY7FD5VjCljokO6fZ2mo0gs3MCTc450af6paLeMPR/IzcsOcJAviqMhkwaEf0ov4+r1UJZYLI8beMf7PgNht6J2D53BCBYggFh/rjWgAIAD9MZ0oOxOPjPojOYhTQ/xiIIekIOJ6AVgcfE4L/+N9VWJfBGxyFaIoF3TgDHpO/S5q+/9O2HlknCliKuDKaVZy/6Oahw7+dSYW689Qiq3725d8D+6uvfuBOd669BV2CBD+A=="
Feb 19 01:24:15 volumio go-librespot[19944]: time="2026-02-19T01:24:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:15 volumio volumio[19606]: info: Initializing connection to go-librespot Websocket
Feb 19 01:24:15 volumio go-librespot[19944]: time="2026-02-19T01:24:15+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:15 volumio go-librespot[19944]: time="2026-02-19T01:24:15+07:00" level=debug msg="completed challenge"
Feb 19 01:24:15 volumio go-librespot[19944]: time="2026-02-19T01:24:15+07:00" level=debug msg="new websocket client"
Feb 19 01:24:15 volumio volumio[19606]: info: Connection to go-librespot Websocket established
Feb 19 01:24:15 volumio go-librespot[19944]: time="2026-02-19T01:24: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 19 01:24:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:15 volumio volumio[19606]: info: Connection to go-librespot Websocket closed
Feb 19 01:24:18 volumio volumio[19606]: info: Getting Spotify volume
Feb 19 01:24:18 volumio volumio[19606]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 19 01:24:18 volumio volumio[19606]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 19 01:24:18 volumio volumio[19606]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 19 01:24:18 volumio volumio[19606]: errno: -111,
Feb 19 01:24:18 volumio volumio[19606]: code: 'ECONNREFUSED',
Feb 19 01:24:18 volumio volumio[19606]: syscall: 'connect',
Feb 19 01:24:18 volumio volumio[19606]: address: '127.0.0.1',
Feb 19 01:24:18 volumio volumio[19606]: port: 9879,
Feb 19 01:24:18 volumio volumio[19606]: response: undefined
Feb 19 01:24:18 volumio volumio[19606]: }
Feb 19 01:24:18 volumio volumio[19606]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 19 01:24:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 19 01:24:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:19 volumio go-librespot[19963]: go-librespot daemon starting...
Feb 19 01:24:19 volumio go-librespot[19964]: time="2026-02-19T01:24:19+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:19 volumio go-librespot[19964]: time="2026-02-19T01:24:19+07:00" level=debug msg="app state loaded"
Feb 19 01:24:19 volumio go-librespot[19964]: time="2026-02-19T01:24:19+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:19 volumio go-librespot[19964]: time="2026-02-19T01:24:19+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 19 01:24:19 volumio go-librespot[19964]: time="2026-02-19T01:24:19+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 19 01:24:19 volumio go-librespot[19964]: time="2026-02-19T01:24:19+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 19 01:24:19 volumio go-librespot[19964]: time="2026-02-19T01:24:19+07:00" level=info msg="zeroconf server listening on port 32905"
Feb 19 01:24:19 volumio go-librespot[19964]: time="2026-02-19T01:24:19+07:00" level=debug msg="obtained new client token: AACsTaysucpETX5ozeTOsxqoxyXigV3pAxE9Y817VH1spDBGYLDjsSWbEgSSd4s/PtG+lD4SXbzEqD/rQRrk/31sS4A6Xz9oz9hvv8+YFS1MSDfHi6/X9qNouh+Gjhkl3M/My/fuw/eUblb2Hhka9fVh6v0uni8EXUadTwRGoNDKuf3uIFn2hVs7hS3vtNRC0vPYXtuJnhd5P/SOtw2kjxfRH94s5B0vJsT+YV/X72CdHnp2+YeU/RBdUQ=="
Feb 19 01:24:20 volumio go-librespot[19964]: time="2026-02-19T01:24:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:20 volumio go-librespot[19964]: time="2026-02-19T01:24:20+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:20 volumio go-librespot[19964]: time="2026-02-19T01:24:20+07:00" level=debug msg="completed challenge"
Feb 19 01:24:20 volumio go-librespot[19964]: time="2026-02-19T01:24:20+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 19 01:24:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:20 volumio sudo[19988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-19 01:23'
Feb 19 01:24:20 volumio sudo[19988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:20 volumio sudo[19988]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:20 volumio volumio-remote-updater[25144]: [2026-02-19 01:24:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 19 01:24:20 volumio volumio-remote-updater[25144]: [2026-02-19 01:24:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 19 01:24:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 19 01:24:20 volumio systemd[1]: volumio.service: Consumed 49.299s CPU time.
Feb 19 01:24:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 19 01:24:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 19 01:24:21 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22696.
Feb 19 01:24:21 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 19 01:24:21 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 19 01:24:21 volumio systemd[1]: volumio.service: Consumed 49.299s CPU time.
Feb 19 01:24:21 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 19 01:24:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 19 01:24:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 19 01:24:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:23 volumio go-librespot[20015]: go-librespot daemon starting...
Feb 19 01:24:23 volumio go-librespot[20016]: time="2026-02-19T01:24:23+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:23 volumio go-librespot[20016]: time="2026-02-19T01:24:23+07:00" level=debug msg="app state loaded"
Feb 19 01:24:23 volumio go-librespot[20016]: time="2026-02-19T01:24:23+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:23 volumio go-librespot[20016]: time="2026-02-19T01:24:23+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 19 01:24:23 volumio go-librespot[20016]: time="2026-02-19T01:24:23+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 19 01:24:23 volumio go-librespot[20016]: time="2026-02-19T01:24:23+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 19 01:24:23 volumio go-librespot[20016]: time="2026-02-19T01:24:23+07:00" level=info msg="zeroconf server listening on port 38805"
Feb 19 01:24:24 volumio go-librespot[20016]: time="2026-02-19T01:24:24+07:00" level=debug msg="obtained new client token: AAB9FFeETjmBIX5iEGz+/WWrhY4LNEjCWjfG+oDYs3N2OKCs+y2PUsIOChDD14H5qYpS13NG5bj00XEL+e62kUfEHVP222YH7fSe/25fyFZkTUzpaq21XvnhuVO3Zwq11xTT3gp7lxCWKJgRKoA1OoJ5Ra3XFtoTuu/WkpSOhGolatk5wNcCxgl2yxF95bFlqj2xz8NTWDYnSHC3YqesJxHdi77AFb9ooXiRP58V5z/iJezLph7AP40="
Feb 19 01:24:24 volumio go-librespot[20016]: time="2026-02-19T01:24:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:24 volumio go-librespot[20016]: time="2026-02-19T01:24:24+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:24 volumio go-librespot[20016]: time="2026-02-19T01:24:24+07:00" level=debug msg="completed challenge"
Feb 19 01:24:24 volumio go-librespot[20016]: time="2026-02-19T01:24:24+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 19 01:24:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:24 volumio volumio[20000]: info: -------------------------------------------
Feb 19 01:24:24 volumio volumio[20000]: info: ----- Volumio3 ----
Feb 19 01:24:24 volumio volumio[20000]: info: -------------------------------------------
Feb 19 01:24:24 volumio volumio[20000]: info: ----- System startup ----
Feb 19 01:24:24 volumio volumio[20000]: info: -------------------------------------------
Feb 19 01:24:25 volumio volumio-remote-updater[25144]: [2026-02-19 01:24:25] [connect] Successful connection
Feb 19 01:24:26 volumio volumio[20000]: info: MYVOLUMIO Environment detected
Feb 19 01:24:26 volumio volumio[20000]: info: Plugin folders cleanup
Feb 19 01:24:26 volumio volumio[20000]: info: Scanning into folder /volumio/app/plugins/
Feb 19 01:24:26 volumio volumio[20000]: info: Scanning category audio_interface
Feb 19 01:24:26 volumio volumio[20000]: info: Scanning category miscellanea
Feb 19 01:24:26 volumio volumio[20000]: info: Scanning category music_service
Feb 19 01:24:26 volumio volumio[20000]: info: Scanning category plugins.json
Feb 19 01:24:26 volumio volumio[20000]: info: Scanning category system_controller
Feb 19 01:24:26 volumio volumio[20000]: info: Scanning category user_interface
Feb 19 01:24:26 volumio volumio[20000]: info: Scanning into folder /data/plugins/
Feb 19 01:24:26 volumio volumio[20000]: info: Scanning category music_service
Feb 19 01:24:26 volumio volumio[20000]: info: Plugin folders cleanup completed
Feb 19 01:24:26 volumio volumio[20000]: info: -------------------------------------------
Feb 19 01:24:26 volumio volumio[20000]: info: ----- Core plugins startup ----
Feb 19 01:24:26 volumio volumio[20000]: info: -------------------------------------------
Feb 19 01:24:26 volumio volumio[20000]: info: Loading plugins from folder /volumio/app/plugins/
Feb 19 01:24:26 volumio volumio[20000]: info: Adding plugin upnp to MyMusic Plugins
Feb 19 01:24:26 volumio volumio[20000]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 19 01:24:26 volumio volumio[20000]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 19 01:24:26 volumio volumio[20000]: info: Loading plugins from folder /data/plugins/
Feb 19 01:24:26 volumio volumio[20000]: info: Loading plugin "system"...
Feb 19 01:24:26 volumio volumio[20000]: info: Loading plugin "appearance"...
Feb 19 01:24:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 19 01:24:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:27 volumio go-librespot[20036]: go-librespot daemon starting...
Feb 19 01:24:27 volumio go-librespot[20037]: time="2026-02-19T01:24:27+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:27 volumio go-librespot[20037]: time="2026-02-19T01:24:27+07:00" level=debug msg="app state loaded"
Feb 19 01:24:27 volumio go-librespot[20037]: time="2026-02-19T01:24:27+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:28 volumio volumio[20000]: info: Loading plugin "network"...
Feb 19 01:24:28 volumio volumio[20000]: info: Refreshing Cached IP Addresses
Feb 19 01:24:28 volumio sudo[20045]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 19 01:24:28 volumio sudo[20045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:28 volumio sudo[20045]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:28 volumio sudo[20047]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 19 01:24:28 volumio sudo[20047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:28 volumio volumio[20000]: info: Loading plugin "services"...
Feb 19 01:24:28 volumio sudo[20047]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:28 volumio volumio[20000]: info: Loading plugin "alsa_controller"...
Feb 19 01:24:28 volumio sudo[20055]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 19 01:24:28 volumio sudo[20055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:28 volumio go-librespot[20037]: time="2026-02-19T01:24:28+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 19 01:24:28 volumio go-librespot[20037]: time="2026-02-19T01:24:28+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 19 01:24:28 volumio go-librespot[20037]: time="2026-02-19T01:24:28+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 19 01:24:28 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 19 01:24:28 volumio volumio[20000]: info: Loading plugin "wizard"...
Feb 19 01:24:28 volumio go-librespot[20037]: time="2026-02-19T01:24:28+07:00" level=info msg="zeroconf server listening on port 39627"
Feb 19 01:24:28 volumio volumio[20000]: info: Loading plugin "networkfs"...
Feb 19 01:24:28 volumio volumio[20000]: info: Starting Udev Watcher for removable devices
Feb 19 01:24:28 volumio volumio[20000]: info: Ignoring mount for partition: boot
Feb 19 01:24:28 volumio volumio[20000]: info: Ignoring mount for partition: volumio
Feb 19 01:24:28 volumio volumio[20000]: info: Ignoring mount for partition: volumio_data
Feb 19 01:24:28 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 19 01:24:28 volumio volumio[20000]: info: Loading plugin "volumio_command_line_client"...
Feb 19 01:24:28 volumio volumio[20000]: info: Loading plugin "upnp"...
Feb 19 01:24:28 volumio volumio[20000]: info: [1771439068681] Starting Upmpd Daemon
Feb 19 01:24:28 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 19 01:24:28 volumio volumio[20000]: info: Loading plugin "my_music"...
Feb 19 01:24:28 volumio volumio[20000]: info: Loading plugin "mpd"...
Feb 19 01:24:28 volumio go-librespot[20037]: time="2026-02-19T01:24:28+07:00" level=debug msg="obtained new client token: AABnyDTyKNZFYAMSJDSsxZC9l4kroa1eWxm08zSDBwfAk0XXJj+37ff7NgLDTjgw1F6xucoyBD/zw43vWNOTNwcIMBLT9y+qsSwNfIyudc2fyNg9lD2StN9YN5wcXEbc/wq/byJJvJQKQ9gD4BSZKzmAVSh4UBJEvOZoUBB4Ff9eJ6rINuSI+RtXW7aqsPpmnV6oHYAZQDMb0xpRX3AWy0b1fGtykVthBFNJsWKVYn7PjfJSgbjpTNZx2g=="
Feb 19 01:24:28 volumio go-librespot[20037]: time="2026-02-19T01:24:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:28 volumio go-librespot[20037]: time="2026-02-19T01:24:28+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:28 volumio go-librespot[20037]: time="2026-02-19T01:24:28+07:00" level=debug msg="completed challenge"
Feb 19 01:24:29 volumio go-librespot[20037]: time="2026-02-19T01:24:29+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 19 01:24:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:29 volumio volumio[20000]: info: Loading plugin "upnp_browser"...
Feb 19 01:24:31 volumio sudo[20055]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:32 volumio volumio[20000]: info: Starting UPNP Browser
Feb 19 01:24:32 volumio volumio[20000]: info: Loading plugin "alarm-clock"...
Feb 19 01:24:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 19 01:24:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:32 volumio go-librespot[20079]: go-librespot daemon starting...
Feb 19 01:24:32 volumio go-librespot[20080]: time="2026-02-19T01:24:32+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:32 volumio go-librespot[20080]: time="2026-02-19T01:24:32+07:00" level=debug msg="app state loaded"
Feb 19 01:24:32 volumio go-librespot[20080]: time="2026-02-19T01:24:32+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:32 volumio volumio[20000]: info: Loading plugin "airplay_emulation"...
Feb 19 01:24:32 volumio volumio[20000]: info: Starting Shairport Sync
Feb 19 01:24:32 volumio volumio[20000]: info: Loading plugin "last_100"...
Feb 19 01:24:32 volumio volumio[20000]: info: Loading plugin "webradio"...
Feb 19 01:24:32 volumio volumio[20000]: info: Loading plugin "i2s_dacs"...
Feb 19 01:24:32 volumio volumio[20000]: info: Loading plugin "volumiodiscovery"...
Feb 19 01:24:32 volumio volumio[20000]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 19 01:24:32 volumio volumio[20000]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 19 01:24:32 volumio volumio[20000]: *** WARNING *** For more information see
Feb 19 01:24:32 volumio volumio[20000]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 19 01:24:32 volumio volumio[20000]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 19 01:24:32 volumio volumio[20000]: *** WARNING *** For more information see
Feb 19 01:24:32 volumio node[20000]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 19 01:24:32 volumio node[20000]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 19 01:24:32 volumio node[20000]: *** WARNING *** For more information see
Feb 19 01:24:32 volumio node[20000]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 19 01:24:32 volumio node[20000]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 19 01:24:32 volumio node[20000]: *** WARNING *** For more information see
Feb 19 01:24:32 volumio volumio[20000]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 19 01:24:32 volumio volumio[20000]: info: Discovery: Started advertising with name: Volumio
Feb 19 01:24:32 volumio go-librespot[20080]: time="2026-02-19T01:24:32+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 19 01:24:32 volumio go-librespot[20080]: time="2026-02-19T01:24:32+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 19 01:24:32 volumio go-librespot[20080]: time="2026-02-19T01:24:32+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 19 01:24:33 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 19 01:24:33 volumio volumio[20000]: info: Loading plugin "spop"...
Feb 19 01:24:33 volumio go-librespot[20080]: time="2026-02-19T01:24:33+07:00" level=info msg="zeroconf server listening on port 33471"
Feb 19 01:24:33 volumio go-librespot[20080]: time="2026-02-19T01:24:33+07:00" level=debug msg="obtained new client token: AACN2EhQGkNrEYoRdi+1Jbe0IC5kKHwdUD1rEYZi+9wwaZizcJBtVq/7rgb5ZHdpVNbp3TcTccnkPxMiJIOU9ORzpKnVdL6W7KQ4zkJtf9hUXevUti2/vTH45ibrw3uiw79K3QQ3SKRIafBWtgqX4onvgB3PQaw9O1yvkfOyJQ90doTI+tXm/Yw11BMmGLy01Py9v5NcjoPARBw8e0sq6muo8MZNC5URUBJi5rudx6ipV3r4cmmrBD8="
Feb 19 01:24:33 volumio go-librespot[20080]: time="2026-02-19T01:24:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:33 volumio go-librespot[20080]: time="2026-02-19T01:24:33+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:33 volumio go-librespot[20080]: time="2026-02-19T01:24:33+07:00" level=debug msg="completed challenge"
Feb 19 01:24:33 volumio go-librespot[20080]: time="2026-02-19T01:24:33+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 19 01:24:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:34 volumio volumio[20000]: info: Loading plugin "ytcr"...
Feb 19 01:24:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 19 01:24:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:36 volumio go-librespot[20089]: go-librespot daemon starting...
Feb 19 01:24:36 volumio go-librespot[20090]: time="2026-02-19T01:24:36+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:36 volumio go-librespot[20090]: time="2026-02-19T01:24:36+07:00" level=debug msg="app state loaded"
Feb 19 01:24:36 volumio go-librespot[20090]: time="2026-02-19T01:24:36+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:37 volumio go-librespot[20090]: time="2026-02-19T01:24: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 19 01:24:37 volumio go-librespot[20090]: time="2026-02-19T01:24:37+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 19 01:24:37 volumio go-librespot[20090]: time="2026-02-19T01:24:37+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 19 01:24:37 volumio go-librespot[20090]: time="2026-02-19T01:24:37+07:00" level=info msg="zeroconf server listening on port 40619"
Feb 19 01:24:37 volumio volumio[20000]: info: Loading plugin "ytmusic"...
Feb 19 01:24:37 volumio go-librespot[20090]: time="2026-02-19T01:24:37+07:00" level=debug msg="obtained new client token: AADMPVv39tNykrHLhhlKIdPrqIKr4cQudhSCUilEE1ZWCXYC93X7w5zvuFzUvYZRueFNYQQ6E2IzsaCO32dcXhI6gUmr9X6CwqPwzaCrx2bsyesad9MlIw9RdKvG81xtij/5VFFiDgdi7MV7VZxejyQZfFzcR4DWNIEqh6Dqf0cHrgXmc0SzSHtssr7zgA7A1dOtwrtt5w6gVoMoIxAWG9lJxKF7e5mWPsl2Uc1XBBoWecIRpddKr/oQbA=="
Feb 19 01:24:37 volumio go-librespot[20090]: time="2026-02-19T01:24:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:37 volumio go-librespot[20090]: time="2026-02-19T01:24:37+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:37 volumio go-librespot[20090]: time="2026-02-19T01:24:37+07:00" level=debug msg="completed challenge"
Feb 19 01:24:37 volumio go-librespot[20090]: time="2026-02-19T01:24:37+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 19 01:24:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:38 volumio volumio-remote-updater[25144]: [2026-02-19 01:24:38] [connect] Successful connection
Feb 19 01:24:38 volumio volumio[20000]: info: Loading plugin "outputs"...
Feb 19 01:24:38 volumio volumio[20000]: info: Loading plugin "albumart"...
Feb 19 01:24:38 volumio volumio[20000]: info: Plugin example_plugin is not enabled
Feb 19 01:24:38 volumio volumio[20000]: info: Loading plugin "inputs"...
Feb 19 01:24:38 volumio volumio[20000]: info: Loading plugin "updater_comm"...
Feb 19 01:24:38 volumio volumio[20000]: info: Plugin mpdemulation is not enabled
Feb 19 01:24:38 volumio volumio[20000]: info: Loading plugin "rest_api"...
Feb 19 01:24:38 volumio volumio[20000]: info: Loading plugin "websocket"...
Feb 19 01:24:38 volumio volumio[20000]: info: Starting Socket.io Server version 1.7.4
Feb 19 01:24:38 volumio volumio[20000]: info: Loading plugin "RoonBridge"...
Feb 19 01:24:39 volumio volumio[20000]: info: Applying required configuration parameters for plugin RoonBridge
Feb 19 01:24:39 volumio volumio[20000]: info: Loading i18n strings for locale en
Feb 19 01:24:39 volumio volumio[20000]: Updating browse sources language
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::initPlayerControls
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 19 01:24:39 volumio volumio[20000]: Express server listening on port 3000
Feb 19 01:24:39 volumio volumio[20000]: [Metrics] WebUI: 16s 39.44ms
Feb 19 01:24:39 volumio volumio[20112]: Forking 3 albumart workers
Feb 19 01:24:39 volumio volumio[20000]: info: CoreStateMachine::resetVolumioState
Feb 19 01:24:39 volumio volumio[20000]: info: CoreStateMachine::getcurrentVolume
Feb 19 01:24:39 volumio volumio[20000]: info: CoreCommandRouter::volumioRetrievevolume
Feb 19 01:24:39 volumio sudo[20146]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 19 01:24:39 volumio sudo[20146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:40 volumio sudo[20146]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:40 volumio sudo[20156]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 19 01:24:40 volumio sudo[20156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:40 volumio sudo[20156]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:40 volumio volumio[20000]: info: Volumio Network Manager: Network status updated: 1
Feb 19 01:24:40 volumio volumio[20000]: info: VolumeController:: Volume=100 Mute =false
Feb 19 01:24:40 volumio volumio[20000]: info: CoreStateMachine::pushState
Feb 19 01:24:40 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:40 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 19 01:24:40 volumio volumio[20000]: info: CoreCommandRouter::volumioPushState
Feb 19 01:24:40 volumio volumio[20000]: info: CoreStateMachine::updateTrackBlock
Feb 19 01:24:40 volumio volumio[20000]: info: CorePlayQueue::getTrackBlock
Feb 19 01:24:40 volumio volumio[20000]: info: CoreCommandRouter::volumioRetrievevolume
Feb 19 01:24:40 volumio volumio-remote-updater[25144]: [2026-02-19 01:24:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771439078 101
Feb 19 01:24:40 volumio volumio[20000]: 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 19 01:24:40 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:40 volumio volumio[20000]: info: Reloading queue from file
Feb 19 01:24:40 volumio volumio[20000]: info: CoreStateMachine::setRepeat null single undefined
Feb 19 01:24:40 volumio volumio[20000]: info: CoreStateMachine::pushState
Feb 19 01:24:40 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:40 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 19 01:24:40 volumio volumio[20000]: info: CoreCommandRouter::volumioPushState
Feb 19 01:24:40 volumio volumio[20000]: info: CoreStateMachine::setRandom null
Feb 19 01:24:40 volumio volumio[20000]: info: CoreStateMachine::pushState
Feb 19 01:24:40 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:40 volumio volumio[20000]: info: CoreCommandRouter::volumioPushState
Feb 19 01:24:40 volumio volumio[20000]: info: Setting Device type: Raspberry PI
Feb 19 01:24:40 volumio volumio[20000]: info: Completed loading Core Plugins
Feb 19 01:24:40 volumio volumio[20000]: info: Preparing to generate the ALSA configuration file
Feb 19 01:24:40 volumio volumio[20000]: info: VolumeController:: Volume=100 Mute =false
Feb 19 01:24:40 volumio volumio[20000]: info: CoreStateMachine::pushState
Feb 19 01:24:40 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:40 volumio volumio[20000]: info: CoreCommandRouter::volumioPushState
Feb 19 01:24:40 volumio volumio[20000]: info: Asound.conf file unchanged, so no further update is needed
Feb 19 01:24:40 volumio volumio[20000]: info: Output device has changed, restarting MPD
Feb 19 01:24:40 volumio volumio[20000]: info: Output device has changed, restarting Shairport Sync
Feb 19 01:24:40 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:40 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:40 volumio sudo[20173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 19 01:24:41 volumio sudo[20173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:41 volumio sudo[20175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 19 01:24:41 volumio sudo[20175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:41 volumio sudo[20175]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 19 01:24:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:41 volumio sudo[20177]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 19 01:24:41 volumio sudo[20177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:41 volumio volumio[20000]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 19 01:24:41 volumio volumio[20000]: info: ___________ START PLUGINS ___________
Feb 19 01:24:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:41 volumio volumio[20000]: info: ControllerMpd::onStart: Initializing MPD
Feb 19 01:24:41 volumio volumio[20000]: info: Creating MPD Configuration file
Feb 19 01:24:41 volumio go-librespot[20184]: go-librespot daemon starting...
Feb 19 01:24:41 volumio go-librespot[20186]: time="2026-02-19T01:24:41+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:41 volumio go-librespot[20186]: time="2026-02-19T01:24:41+07:00" level=debug msg="app state loaded"
Feb 19 01:24:41 volumio sudo[20173]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:41 volumio go-librespot[20186]: time="2026-02-19T01:24:41+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:24:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 19 01:24:41 volumio sudo[20193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 19 01:24:41 volumio sudo[20193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:41 volumio volumio[20000]: info: [1771439081261] CoreMusicLibrary::Adding element Media Servers
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:41 volumio sudo[20193]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:41 volumio sudo[20195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 19 01:24:41 volumio sudo[20195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:41 volumio volumio[20000]: info: UPNP Browser: Client initialized successfully
Feb 19 01:24:41 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 19 01:24:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 19 01:24:41 volumio systemd[1]: mpd.service: Consumed 7.126s CPU time.
Feb 19 01:24:41 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 19 01:24:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 19 01:24:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 19 01:24:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 19 01:24:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:41 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 19 01:24:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 19 01:24:41 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 19 01:24:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 19 01:24:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 19 01:24:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 19 01:24:41 volumio volumio[20000]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 19 01:24:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:41 volumio volumio[20000]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:24:41 volumio volumio[20000]: info: [1771439081772] CoreMusicLibrary::Adding element Last_100
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:24:41 volumio volumio[20000]: info: [1771439081787] CoreMusicLibrary::Adding element Webradio
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:41 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 19 01:24:41 volumio volumio[20000]: info: Initializing BBC Radios
Feb 19 01:24:41 volumio go-librespot[20186]: time="2026-02-19T01:24: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 19 01:24:41 volumio go-librespot[20186]: time="2026-02-19T01:24: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 19 01:24:41 volumio go-librespot[20186]: time="2026-02-19T01:24: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 19 01:24:41 volumio go-librespot[20186]: time="2026-02-19T01:24:41+07:00" level=info msg="zeroconf server listening on port 39117"
Feb 19 01:24:42 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 19 01:24:42 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:42 volumio volumio[20000]: info: Creating Spotify config file
Feb 19 01:24:42 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:42 volumio go-librespot[20186]: time="2026-02-19T01:24:42+07:00" level=debug msg="obtained new client token: AACOpyOCm+A//jFLW3GMo6RVnyGUfheov+HsiDTAaRf5Z1jKJ3WdLQ6QikEx/UIPmJtTL5AOCQlmOxzOGWQraIll5QGnhVAqfUBtpPaFpyuCVPinM7MkWcNkuqHayMDGnS7T75u1sXCqi2nLBJ3Wrqh9bJTr9+nD4v9Rb9QDtvX7KjIHOERbhE5Qen142sGO1su3pndTc0ihN/AWScsl4eirnQA1Mb2SokU9rR7UBioQ1nZ9zlwg5cc="
Feb 19 01:24:42 volumio sudo[20206]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 19 01:24:42 volumio sudo[20206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 19 01:24:42 volumio sudo[20206]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:42 volumio go-librespot[20186]: time="2026-02-19T01:24:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:42 volumio go-librespot[20186]: time="2026-02-19T01:24:42+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:42 volumio go-librespot[20186]: time="2026-02-19T01:24:42+07:00" level=debug msg="completed challenge"
Feb 19 01:24:42 volumio go-librespot[20186]: time="2026-02-19T01:24: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 19 01:24:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:43 volumio volumio[20126]: Starting albumart workers
Feb 19 01:24:43 volumio volumio[20127]: Starting albumart workers
Feb 19 01:24:43 volumio volumio[20000]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:24:43 volumio volumio[20000]: info: [1771439083343] CoreMusicLibrary::Adding element YouTube Music
Feb 19 01:24:43 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:43 volumio volumio[20000]: Cannot find translation for source YouTube Music
Feb 19 01:24:43 volumio volumio[20000]: info: Volumio Calling Home
Feb 19 01:24:43 volumio sudo[20227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 19 01:24:43 volumio sudo[20227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:43 volumio sudo[20227]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:43 volumio volumio[20125]: Starting albumart workers
Feb 19 01:24:44 volumio volumio[20000]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 19 01:24:44 volumio volumio[20000]: info: Discovery: Found device Volumio
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::volumioGetState
Feb 19 01:24:44 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:44 volumio volumio[20000]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7
Feb 19 01:24:44 volumio volumio[20000]: info: Discovery: Found device Volumio
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::volumioGetState
Feb 19 01:24:44 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:44 volumio volumio[20000]: info: MPD Permissions set
Feb 19 01:24:44 volumio volumio[20000]: info: MPD Permissions set
Feb 19 01:24:44 volumio volumio[20000]: info: Upmpdcli Daemon Started
Feb 19 01:24:44 volumio volumio[20000]: info: Spotify config file written
Feb 19 01:24:44 volumio sudo[20234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 19 01:24:44 volumio sudo[20234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:44 volumio volumio[20000]: 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 19 01:24:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio go-librespot[20236]: go-librespot daemon starting...
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio sudo[20234]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:44 volumio go-librespot[20242]: time="2026-02-19T01:24:44+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:44 volumio go-librespot[20242]: time="2026-02-19T01:24:44+07:00" level=debug msg="app state loaded"
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:24:44 volumio go-librespot[20242]: time="2026-02-19T01:24:44+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:44 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:24:44 volumio volumio[20000]: info: No need to fix Spotify hosts
Feb 19 01:24:45 volumio go-librespot[20242]: time="2026-02-19T01:24: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-gew4.spotify.com:80]"
Feb 19 01:24:45 volumio go-librespot[20242]: time="2026-02-19T01:24:45+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 19 01:24:45 volumio go-librespot[20242]: time="2026-02-19T01:24:45+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 19 01:24:45 volumio go-librespot[20242]: time="2026-02-19T01:24:45+07:00" level=info msg="zeroconf server listening on port 33407"
Feb 19 01:24:45 volumio volumio[20000]: info: Volumio called home
Feb 19 01:24:45 volumio go-librespot[20242]: time="2026-02-19T01:24:45+07:00" level=debug msg="obtained new client token: AACt5j+fT55xW/vgj+YmMN+cZBcrY9pBwxqIXhT5C00y1MhrwzXU7e365EEqs4JoQOXBwfvUbozi4F0Vf6IgEmorzQbbpLRDcfIGdBddqEy+n1xK5C0xkYHcf9+yl8J+82CYB5YlhCvbn4Lag3RJHdFSW/WPlEnN/AHs+J2yxQ2UOxqbltI4kt4r45jz5DeZ4LmmKLQasL29sYEHd+JytY6PrkjTlY12BD3kJVRCcDWHCpFujSSDuUOzeQ=="
Feb 19 01:24:45 volumio go-librespot[20242]: time="2026-02-19T01:24:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:45 volumio volumio[20000]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 19 01:24:45 volumio volumio[20000]: SPOTIFY: BQBImhZG9L31MvWlFy_UlvxUuRx3C8Dgu4lBXMeljUZepj1oDn7KJTHIlVkQhOKZfvk8_34lWMS9wpW4c69nNWPSXf0PZMdY2PM6WtHyAAME9wbCQRk_IO1pP0NI7WPgn-BAXyOGXlK82eQ3WzSZ4NIyH_mHTh6sF0R1OVDOCvpp1YV55x-A1jaPsHN2g4guskHG5Cei5Ob0Umoz4leApMsvcZdu9i6tY_ocuGXMkXpJubGP_voUNpm9h8bD1D3jYw8QlHteS9SeVHa0Gc6pCLZk5chbEBeIYHSrrhLycDPIYPqv_N6XJumP
Feb 19 01:24:45 volumio volumio[20000]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 19 01:24:45 volumio volumio[20000]: info: New Spotify access token = BQBImhZG9L31MvWlFy_UlvxUuRx3C8Dgu4lBXMeljUZepj1oDn7KJTHIlVkQhOKZfvk8_34lWMS9wpW4c69nNWPSXf0PZMdY2PM6WtHyAAME9wbCQRk_IO1pP0NI7WPgn-BAXyOGXlK82eQ3WzSZ4NIyH_mHTh6sF0R1OVDOCvpp1YV55x-A1jaPsHN2g4guskHG5Cei5Ob0Umoz4leApMsvcZdu9i6tY_ocuGXMkXpJubGP_voUNpm9h8bD1D3jYw8QlHteS9SeVHa0Gc6pCLZk5chbEBeIYHSrrhLycDPIYPqv_N6XJumP
Feb 19 01:24:45 volumio volumio[20000]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 19 01:24:46 volumio volumio[20000]: info: Starting Shairport Sync
Feb 19 01:24:46 volumio volumio[20000]: info: Starting Shairport Sync
Feb 19 01:24:46 volumio volumio[20000]: info: Starting Shairport Sync
Feb 19 01:24:46 volumio go-librespot[20242]: time="2026-02-19T01:24:46+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:46 volumio go-librespot[20242]: time="2026-02-19T01:24:46+07:00" level=debug msg="completed challenge"
Feb 19 01:24:46 volumio sudo[20273]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 19 01:24:46 volumio sudo[20273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:46 volumio sudo[20277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 19 01:24:46 volumio sudo[20277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:46 volumio go-librespot[20242]: time="2026-02-19T01:24: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 19 01:24:46 volumio sudo[20275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 19 01:24:46 volumio sudo[20275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:24:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:46 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 19 01:24:46 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 19 01:24:46 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 19 01:24:46 volumio systemd[1]: shairport-sync.service: Consumed 2.255s CPU time.
Feb 19 01:24:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 19 01:24:46 volumio sudo[20275]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:46 volumio sudo[20273]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:46 volumio sudo[20277]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:46 volumio volumio[20000]: info: Shairport-Sync Started
Feb 19 01:24:46 volumio volumio[20000]: Error adding Membership: Error: addMembership EINVAL
Feb 19 01:24:46 volumio volumio[20000]: info: CoreCommandRouter::volumioGetState
Feb 19 01:24:46 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:46 volumio volumio[20000]: info: Shairport-Sync Started
Feb 19 01:24:46 volumio volumio[20000]: info: Shairport-Sync Started
Feb 19 01:24:46 volumio volumio[20000]: 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 19 01:24:46 volumio volumio[20000]: info: Spotify Successfully logged in
Feb 19 01:24:46 volumio volumio[20000]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:24:46 volumio volumio[20000]: info: [1771439086880] CoreMusicLibrary::Adding element Spotify
Feb 19 01:24:46 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:24:46 volumio volumio[20000]: Cannot find translation for source YouTube Music
Feb 19 01:24:46 volumio volumio[20000]: Cannot find translation for source Spotify
Feb 19 01:24:47 volumio volumio[20000]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 19 01:24:47 volumio volumio[20000]: info: CoreCommandRouter::volumioRetrievevolume
Feb 19 01:24:47 volumio volumio[20000]: info: VolumeController:: Volume=100 Mute =false
Feb 19 01:24:47 volumio volumio[20000]: info: CoreCommandRouter::volumioGetState
Feb 19 01:24:47 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:47 volumio volumio[20000]: info: CoreStateMachine::pushState
Feb 19 01:24:47 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:24:47 volumio volumio[20000]: info: CoreCommandRouter::volumioPushState
Feb 19 01:24:48 volumio volumio[20000]: info: go-librespot daemon successfully initialized
Feb 19 01:24:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 19 01:24:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:49 volumio mpd[20225]: 2026-02-19T01:24:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 19 01:24:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:49 volumio go-librespot[20313]: go-librespot daemon starting...
Feb 19 01:24:49 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 19 01:24:49 volumio sudo[20195]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:49 volumio sudo[20177]: pam_unix(sudo:session): session closed for user root
Feb 19 01:24:49 volumio go-librespot[20316]: time="2026-02-19T01:24:49+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:49 volumio go-librespot[20316]: time="2026-02-19T01:24:49+07:00" level=debug msg="app state loaded"
Feb 19 01:24:49 volumio go-librespot[20316]: time="2026-02-19T01:24:49+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:49 volumio volumio[20000]: error: MPD error: The expression evaluated to a falsy value:
Feb 19 01:24:49 volumio volumio[20000]: assert.ok(self.idling)
Feb 19 01:24:49 volumio volumio[20000]: error: The expression evaluated to a falsy value:
Feb 19 01:24:49 volumio volumio[20000]: assert.ok(self.idling)
Feb 19 01:24:49 volumio volumio[20000]: info: Completed starting Core Plugins
Feb 19 01:24:49 volumio volumio[20000]: info: -------------------------------------------
Feb 19 01:24:49 volumio volumio[20000]: info: ----- MyVolumio plugins startup ----
Feb 19 01:24:49 volumio volumio[20000]: info: -------------------------------------------
Feb 19 01:24:49 volumio volumio[20000]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 19 01:24:49 volumio volumio[20000]: error: updateQueue error: null
Feb 19 01:24:49 volumio volumio[20000]: info: MPD running with PID20225
Feb 19 01:24:49 volumio volumio[20000]: ,establishing connection
Feb 19 01:24:49 volumio volumio[20000]: error: updateQueue error: null
Feb 19 01:24:49 volumio go-librespot[20316]: time="2026-02-19T01:24: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 19 01:24:49 volumio go-librespot[20316]: time="2026-02-19T01:24: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 19 01:24:49 volumio go-librespot[20316]: time="2026-02-19T01:24: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 19 01:24:49 volumio go-librespot[20316]: time="2026-02-19T01:24:49+07:00" level=info msg="zeroconf server listening on port 36975"
Feb 19 01:24:50 volumio go-librespot[20316]: time="2026-02-19T01:24:50+07:00" level=debug msg="obtained new client token: AAB+6T7BDzqbxzIW9qB+Fb3NCG3g6G8rTQYHofFF47ZskXgg5FgHfY23bJAVU5XWGe5yfGkbqy7prSjfL/HmkmLOxdJqDtRkp1S+eCxRPfqj4SS+v62MLDFsspoj7jDCP13f6jehs57IovEmQiZcctlIFfwagFZRtH+6yr28ow3oGkqK5acGM9x0zKS6uwp1tu4/RlrNE9+37xQggItkQvlNur/ApW5GVg9Y56W1YHZu3ulZzGCPCxI="
Feb 19 01:24:50 volumio go-librespot[20316]: time="2026-02-19T01:24:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:50 volumio go-librespot[20316]: time="2026-02-19T01:24:50+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:50 volumio go-librespot[20316]: time="2026-02-19T01:24:50+07:00" level=debug msg="completed challenge"
Feb 19 01:24:50 volumio go-librespot[20316]: time="2026-02-19T01:24: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 19 01:24:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:51 volumio volumio[20000]: info: Initializing connection to go-librespot Websocket
Feb 19 01:24:51 volumio volumio[20000]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 19 01:24:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 19 01:24:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:53 volumio go-librespot[20325]: go-librespot daemon starting...
Feb 19 01:24:53 volumio go-librespot[20326]: time="2026-02-19T01:24:53+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:53 volumio go-librespot[20326]: time="2026-02-19T01:24:53+07:00" level=debug msg="app state loaded"
Feb 19 01:24:53 volumio go-librespot[20326]: time="2026-02-19T01:24:53+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:54 volumio go-librespot[20326]: time="2026-02-19T01:24: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 19 01:24:54 volumio go-librespot[20326]: time="2026-02-19T01:24:54+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 19 01:24:54 volumio go-librespot[20326]: time="2026-02-19T01:24:54+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 19 01:24:54 volumio go-librespot[20326]: time="2026-02-19T01:24:54+07:00" level=info msg="zeroconf server listening on port 32789"
Feb 19 01:24:54 volumio go-librespot[20326]: time="2026-02-19T01:24:54+07:00" level=debug msg="obtained new client token: AADMkr3VomYToyp95IFkv/ri7v3+Sjf9MzyZ7rP3YGtwn5RZwdLOVvv2As+nKVojyC0c3BuVUO7Cqq6phoFhYZDLXIPF8CkOF75VniMbJjrVE4q+UuTqpwCOynVEJueJRdxErBXmqYQ5VHPktLEIyABOsxYghAsxBIkiVorGF3Y4MjlBuiW/38GMlRQRYHAgJk+SfrLTCkS7x6KpyRnQDkWVpAijI/XgR77VUWG2TyL4HEhn3O7gr9kN4A=="
Feb 19 01:24:54 volumio go-librespot[20326]: time="2026-02-19T01:24:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:54 volumio volumio[20000]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Feb 19 01:24:54 volumio go-librespot[20326]: time="2026-02-19T01:24:54+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:54 volumio go-librespot[20326]: time="2026-02-19T01:24:54+07:00" level=debug msg="completed challenge"
Feb 19 01:24:54 volumio go-librespot[20326]: time="2026-02-19T01:24: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 19 01:24:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:24:55 volumio volumio[20000]: info: Initializing connection to go-librespot Websocket
Feb 19 01:24:55 volumio volumio[20000]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 19 01:24:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Feb 19 01:24:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:24:57 volumio go-librespot[20333]: go-librespot daemon starting...
Feb 19 01:24:57 volumio go-librespot[20334]: time="2026-02-19T01:24:57+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:24:57 volumio go-librespot[20334]: time="2026-02-19T01:24:57+07:00" level=debug msg="app state loaded"
Feb 19 01:24:57 volumio go-librespot[20334]: time="2026-02-19T01:24:57+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:24:58 volumio volumio[20000]: info: Initializing connection to go-librespot Websocket
Feb 19 01:24:58 volumio go-librespot[20334]: time="2026-02-19T01:24:58+07:00" level=debug msg="new websocket client"
Feb 19 01:24:58 volumio volumio[20000]: info: Connection to go-librespot Websocket established
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 19 01:24:58 volumio volumio[20000]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 19 01:24:58 volumio go-librespot[20334]: time="2026-02-19T01:24: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 19 01:24:58 volumio go-librespot[20334]: time="2026-02-19T01:24:58+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 19 01:24:58 volumio go-librespot[20334]: time="2026-02-19T01:24:58+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 19 01:24:58 volumio volumio[20000]: info: Adding plugin multiroom to MyMusic Plugins
Feb 19 01:24:58 volumio volumio[20000]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 19 01:24:58 volumio volumio[20000]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 19 01:24:58 volumio volumio[20000]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 19 01:24:58 volumio volumio[20000]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 19 01:24:58 volumio volumio[20000]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 19 01:24:58 volumio volumio[20000]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 19 01:24:58 volumio go-librespot[20334]: time="2026-02-19T01:24:58+07:00" level=info msg="zeroconf server listening on port 37645"
Feb 19 01:24:58 volumio go-librespot[20334]: time="2026-02-19T01:24:58+07:00" level=debug msg="obtained new client token: AAAaYQJwJRdnRHiwasZcZ7V20/ajFZo8ik/JD2cwHMdQ6gYY24aqZJXrW6Ls7sZIHuSWazoCoz8cufAuj3yToYcHu2nFQQ3v/T16/wksI9STlIhtUDmP36qjQJ5UFXHfCj4RzgdFYC8B5C/r5ep8wvHMPfsw9YMjjm/+3mYY2jPba9mdxKHdr5nale5dT9+UWnShfIksNcTX6TtuPx2ErBjynJ9/8ABRl0NrWrboY382yl0V4gIuY6Uf7Q=="
Feb 19 01:24:58 volumio go-librespot[20334]: time="2026-02-19T01:24:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:24:58 volumio go-librespot[20334]: time="2026-02-19T01:24:58+07:00" level=debug msg="completed keyexchange"
Feb 19 01:24:58 volumio go-librespot[20334]: time="2026-02-19T01:24:58+07:00" level=debug msg="completed challenge"
Feb 19 01:24:58 volumio go-librespot[20334]: time="2026-02-19T01:24: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 19 01:24:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:24:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:00 volumio volumio[20000]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 19 01:25:00 volumio volumio[20000]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 19 01:25:00 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:00 volumio volumio[20000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:00 volumio volumio[20000]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 19 01:25:00 volumio volumio[20000]: info: MyVolumio login type: Token
Feb 19 01:25:00 volumio volumio[20000]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 19 01:25:00 volumio volumio[20000]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 19 01:25:02 volumio volumio[20000]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 19 01:25:02 volumio volumio[20000]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 19 01:25:02 volumio volumio[20000]: info: Streaming services startup
Feb 19 01:25:02 volumio volumio[20000]: info: Starting Streaming Daemon
Feb 19 01:25:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Feb 19 01:25:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:02 volumio sudo[20357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 19 01:25:02 volumio volumio[20000]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 19 01:25:02 volumio sudo[20357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:02 volumio go-librespot[20362]: go-librespot daemon starting...
Feb 19 01:25:02 volumio sudo[20357]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:02 volumio go-librespot[20364]: time="2026-02-19T01:25:02+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:02 volumio go-librespot[20364]: time="2026-02-19T01:25:02+07:00" level=debug msg="app state loaded"
Feb 19 01:25:02 volumio go-librespot[20364]: time="2026-02-19T01:25:02+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:02 volumio volumio[20000]: info: Getting Spotify volume
Feb 19 01:25:02 volumio volumio[20000]: info: Connection to go-librespot Websocket closed
Feb 19 01:25:02 volumio volumio[20000]: error: Cannot start Volumio Streaming Daemon
Feb 19 01:25:02 volumio volumio[20000]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 19 01:25:02 volumio volumio[20000]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 19 01:25:02 volumio volumio[20000]: 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 19 01:25:02 volumio volumio[20000]: info: CoreCommandRouter::volumioGetState
Feb 19 01:25:02 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:02 volumio volumio[20000]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 19 01:25:02 volumio volumio[20000]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 19 01:25:02 volumio volumio[20000]: SPOTIFY: VOLUMIO VOLUME 100
Feb 19 01:25:02 volumio volumio[20000]: info: Aligning Spotify Volume to Volumio Volume
Feb 19 01:25:02 volumio volumio[20000]: info: CoreCommandRouter::volumioGetState
Feb 19 01:25:02 volumio volumio[20000]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:02 volumio volumio[20000]: info: Setting Spotify Volume from Volumio: 100
Feb 19 01:25:02 volumio go-librespot[20364]: time="2026-02-19T01:25: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 19 01:25:02 volumio go-librespot[20364]: time="2026-02-19T01:25:02+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 19 01:25:02 volumio go-librespot[20364]: time="2026-02-19T01:25:02+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 19 01:25:02 volumio go-librespot[20364]: time="2026-02-19T01:25:02+07:00" level=info msg="zeroconf server listening on port 34623"
Feb 19 01:25:02 volumio go-librespot[20364]: time="2026-02-19T01:25:02+07:00" level=debug msg="obtained new client token: AAAQlbki/I6mF9LMgtjAI+Jgs7lbkzwGlmWId8+LHoLKiPD+Tte0TLbLYiHGIEB8c4jc0bRHxyFGFFGWe/qQs38L+3e9n/X/OirIA18jCELBPExNcEnKHtWJagZLE7qmlpmWh/5w11JdfX9jxJk3KOk0KPQwDE2Bqq8IJpMhOi9PPtW6CygILD4Nh8CdyNkUUCGgA8yLaXpdsvdpuHOEWEidmwIb5ahT8dBbbA9qvVAYxg3NbCVIG3cokQ=="
Feb 19 01:25:03 volumio go-librespot[20364]: time="2026-02-19T01:25:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:03 volumio go-librespot[20364]: time="2026-02-19T01:25:03+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:03 volumio go-librespot[20364]: time="2026-02-19T01:25:03+07:00" level=debug msg="completed challenge"
Feb 19 01:25:03 volumio go-librespot[20364]: time="2026-02-19T01:25: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 19 01:25:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:03 volumio volumio[20000]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 19 01:25:03 volumio volumio[20000]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 19 01:25:03 volumio volumio[20000]: Error: socket hang up
Feb 19 01:25:03 volumio volumio[20000]: at connResetException (node:internal/errors:720:14)
Feb 19 01:25:03 volumio volumio[20000]: at Socket.socketOnEnd (node:_http_client:519:23)
Feb 19 01:25:03 volumio volumio[20000]: at Socket.emit (node:events:526:35)
Feb 19 01:25:03 volumio volumio[20000]: at endReadableNT (node:internal/streams/readable:1376:12)
Feb 19 01:25:03 volumio volumio[20000]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 19 01:25:03 volumio volumio[20000]: code: 'ECONNRESET',
Feb 19 01:25:03 volumio volumio[20000]: response: undefined
Feb 19 01:25:03 volumio volumio[20000]: }
Feb 19 01:25:03 volumio volumio[20000]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 19 01:25:04 volumio sudo[20387]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-19 01:24'
Feb 19 01:25:04 volumio sudo[20387]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:05 volumio sudo[20387]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Feb 19 01:25:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:06 volumio go-librespot[20395]: go-librespot daemon starting...
Feb 19 01:25:06 volumio go-librespot[20396]: time="2026-02-19T01:25:06+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:06 volumio go-librespot[20396]: time="2026-02-19T01:25:06+07:00" level=debug msg="app state loaded"
Feb 19 01:25:06 volumio go-librespot[20396]: time="2026-02-19T01:25:06+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:06 volumio volumio-remote-updater[25144]: [2026-02-19 01:25:06] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Feb 19 01:25:06 volumio volumio-remote-updater[25144]: [2026-02-19 01:25:06] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Feb 19 01:25:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 19 01:25:06 volumio systemd[1]: volumio.service: Consumed 55.633s CPU time.
Feb 19 01:25:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 19 01:25:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 19 01:25:06 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22697.
Feb 19 01:25:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 19 01:25:06 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 19 01:25:06 volumio systemd[1]: volumio.service: Consumed 55.633s CPU time.
Feb 19 01:25:06 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 19 01:25:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 19 01:25:06 volumio go-librespot[20396]: time="2026-02-19T01:25: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 19 01:25:06 volumio go-librespot[20396]: time="2026-02-19T01:25:06+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 19 01:25:06 volumio go-librespot[20396]: time="2026-02-19T01:25:06+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 19 01:25:06 volumio go-librespot[20396]: time="2026-02-19T01:25:06+07:00" level=info msg="zeroconf server listening on port 37989"
Feb 19 01:25:07 volumio go-librespot[20396]: time="2026-02-19T01:25:07+07:00" level=debug msg="obtained new client token: AAAHRusXgFkQo7hZxL/9rPoUMTvsvuqaURqRPC4St3IZfyCSRk9ZBqBydAVNH0gN+A63lftJJ3wfKXqAi1rMRed5NQuRQCFnERB4AxvFBBnCHbFHraVpyIfHXwHFdHPyXrMg9N6VVETmyEe7G3uZamc+GU1SHUv6AIRkrgItcRU3lGBneSKwbTjVy3YLXyOhzaZonY4VfOZmxOtl3IRD2LHm1cBl2kKeyOyOBWgOQqAWBItIxvUp7Zk="
Feb 19 01:25:07 volumio go-librespot[20396]: time="2026-02-19T01:25:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:07 volumio go-librespot[20396]: time="2026-02-19T01:25:07+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:07 volumio go-librespot[20396]: time="2026-02-19T01:25:07+07:00" level=debug msg="completed challenge"
Feb 19 01:25:07 volumio go-librespot[20396]: time="2026-02-19T01:25:07+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 19 01:25:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:10 volumio volumio[20412]: info: -------------------------------------------
Feb 19 01:25:10 volumio volumio[20412]: info: ----- Volumio3 ----
Feb 19 01:25:10 volumio volumio[20412]: info: -------------------------------------------
Feb 19 01:25:10 volumio volumio[20412]: info: ----- System startup ----
Feb 19 01:25:10 volumio volumio[20412]: info: -------------------------------------------
Feb 19 01:25:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Feb 19 01:25:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:10 volumio go-librespot[20433]: go-librespot daemon starting...
Feb 19 01:25:10 volumio go-librespot[20434]: time="2026-02-19T01:25:10+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:10 volumio go-librespot[20434]: time="2026-02-19T01:25:10+07:00" level=debug msg="app state loaded"
Feb 19 01:25:10 volumio go-librespot[20434]: time="2026-02-19T01:25:10+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:11 volumio go-librespot[20434]: time="2026-02-19T01:25: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 19 01:25:11 volumio go-librespot[20434]: time="2026-02-19T01:25:11+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 19 01:25:11 volumio go-librespot[20434]: time="2026-02-19T01:25:11+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 19 01:25:11 volumio go-librespot[20434]: time="2026-02-19T01:25:11+07:00" level=info msg="zeroconf server listening on port 41257"
Feb 19 01:25:11 volumio go-librespot[20434]: time="2026-02-19T01:25:11+07:00" level=debug msg="obtained new client token: AACBiNTYgB6ofY9z/lM3eWYmTuVMc/l7XFW/P2MMeF7E2Ur3jh6vAnd4AB3P1/L8soTS4pQiUeRQG0fM4GpwPDzFFAubtY8YfTopCQM15ngH9UFlTU3fA0ZNHdtUTKZFZDd//p+RikGdVSjLktxkxyBX8QrCpo5CJOaPFtzSXMmSUIqao9SShfK2JHCkMdUnbI7m4ijrxHA2mfzFpuWSl8PaCEU/tfpv3IMVSu1qclgDSkb1NVgCzxM7dg=="
Feb 19 01:25:11 volumio go-librespot[20434]: time="2026-02-19T01:25:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:11 volumio volumio-remote-updater[25144]: [2026-02-19 01:25:11] [connect] Successful connection
Feb 19 01:25:11 volumio go-librespot[20434]: time="2026-02-19T01:25:11+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:11 volumio go-librespot[20434]: time="2026-02-19T01:25:11+07:00" level=debug msg="completed challenge"
Feb 19 01:25:11 volumio go-librespot[20434]: time="2026-02-19T01:25:11+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 19 01:25:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:11 volumio volumio[20412]: info: MYVOLUMIO Environment detected
Feb 19 01:25:12 volumio volumio[20412]: info: Plugin folders cleanup
Feb 19 01:25:12 volumio volumio[20412]: info: Scanning into folder /volumio/app/plugins/
Feb 19 01:25:12 volumio volumio[20412]: info: Scanning category audio_interface
Feb 19 01:25:12 volumio volumio[20412]: info: Scanning category miscellanea
Feb 19 01:25:12 volumio volumio[20412]: info: Scanning category music_service
Feb 19 01:25:12 volumio volumio[20412]: info: Scanning category plugins.json
Feb 19 01:25:12 volumio volumio[20412]: info: Scanning category system_controller
Feb 19 01:25:12 volumio volumio[20412]: info: Scanning category user_interface
Feb 19 01:25:12 volumio volumio[20412]: info: Scanning into folder /data/plugins/
Feb 19 01:25:12 volumio volumio[20412]: info: Scanning category music_service
Feb 19 01:25:12 volumio volumio[20412]: info: Plugin folders cleanup completed
Feb 19 01:25:12 volumio volumio[20412]: info: -------------------------------------------
Feb 19 01:25:12 volumio volumio[20412]: info: ----- Core plugins startup ----
Feb 19 01:25:12 volumio volumio[20412]: info: -------------------------------------------
Feb 19 01:25:12 volumio volumio[20412]: info: Loading plugins from folder /volumio/app/plugins/
Feb 19 01:25:12 volumio volumio[20412]: info: Adding plugin upnp to MyMusic Plugins
Feb 19 01:25:12 volumio volumio[20412]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 19 01:25:12 volumio volumio[20412]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 19 01:25:12 volumio volumio[20412]: info: Loading plugins from folder /data/plugins/
Feb 19 01:25:12 volumio volumio[20412]: info: Loading plugin "system"...
Feb 19 01:25:12 volumio volumio[20412]: info: Loading plugin "appearance"...
Feb 19 01:25:14 volumio volumio[20412]: info: Loading plugin "network"...
Feb 19 01:25:14 volumio volumio[20412]: info: Refreshing Cached IP Addresses
Feb 19 01:25:14 volumio sudo[20449]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 19 01:25:14 volumio sudo[20449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:14 volumio sudo[20451]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 19 01:25:14 volumio sudo[20451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:14 volumio sudo[20449]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:14 volumio volumio[20412]: info: Loading plugin "services"...
Feb 19 01:25:14 volumio volumio[20412]: info: Loading plugin "alsa_controller"...
Feb 19 01:25:14 volumio sudo[20451]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:14 volumio sudo[20461]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 19 01:25:14 volumio sudo[20461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:14 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 19 01:25:14 volumio volumio[20412]: info: Loading plugin "wizard"...
Feb 19 01:25:14 volumio volumio[20412]: info: Loading plugin "networkfs"...
Feb 19 01:25:14 volumio volumio[20412]: info: Starting Udev Watcher for removable devices
Feb 19 01:25:14 volumio volumio[20412]: info: Ignoring mount for partition: boot
Feb 19 01:25:14 volumio volumio[20412]: info: Ignoring mount for partition: volumio
Feb 19 01:25:14 volumio volumio[20412]: info: Ignoring mount for partition: volumio_data
Feb 19 01:25:14 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 19 01:25:14 volumio volumio[20412]: info: Loading plugin "volumio_command_line_client"...
Feb 19 01:25:14 volumio volumio[20412]: info: Loading plugin "upnp"...
Feb 19 01:25:14 volumio volumio[20412]: info: [1771439114445] Starting Upmpd Daemon
Feb 19 01:25:14 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 19 01:25:14 volumio volumio[20412]: info: Loading plugin "my_music"...
Feb 19 01:25:14 volumio volumio[20412]: info: Loading plugin "mpd"...
Feb 19 01:25:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Feb 19 01:25:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:14 volumio go-librespot[20482]: go-librespot daemon starting...
Feb 19 01:25:14 volumio go-librespot[20483]: time="2026-02-19T01:25:14+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:14 volumio go-librespot[20483]: time="2026-02-19T01:25:14+07:00" level=debug msg="app state loaded"
Feb 19 01:25:14 volumio go-librespot[20483]: time="2026-02-19T01:25:14+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:15 volumio volumio[20412]: info: Loading plugin "upnp_browser"...
Feb 19 01:25:15 volumio go-librespot[20483]: time="2026-02-19T01:25:15+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 19 01:25:15 volumio go-librespot[20483]: time="2026-02-19T01:25:15+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 19 01:25:15 volumio go-librespot[20483]: time="2026-02-19T01:25:15+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 19 01:25:15 volumio go-librespot[20483]: time="2026-02-19T01:25:15+07:00" level=info msg="zeroconf server listening on port 34643"
Feb 19 01:25:15 volumio go-librespot[20483]: time="2026-02-19T01:25:15+07:00" level=debug msg="obtained new client token: AACmntu+lrj4nhwUkM7iC4wy91Vg9eIToAvGQUbQq5YyrLu5UyHd6tvuyYj38bkqF0cQQebqCQUXtyyXNgfuNDP2DQgDjGPYe9eFP+LTOpEaVEy7COzCwFw3YXKe0fyxXNq0THbYbyxJugXow4HhtJ+e90RTUP6PwqQgIiL6PxUrp0reKegwLGlepPlEjmEMBmRM4rmnl3YNSecjqjNTmNe3sIXFgqHXXaKarOvzYXriuSXxVr0GrgiVoA=="
Feb 19 01:25:15 volumio go-librespot[20483]: time="2026-02-19T01:25:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:15 volumio go-librespot[20483]: time="2026-02-19T01:25:15+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:15 volumio go-librespot[20483]: time="2026-02-19T01:25:15+07:00" level=debug msg="completed challenge"
Feb 19 01:25:16 volumio go-librespot[20483]: time="2026-02-19T01:25:16+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 19 01:25:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:16 volumio sudo[20461]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:18 volumio volumio[20412]: info: Starting UPNP Browser
Feb 19 01:25:18 volumio volumio[20412]: info: Loading plugin "alarm-clock"...
Feb 19 01:25:18 volumio volumio[20412]: info: Loading plugin "airplay_emulation"...
Feb 19 01:25:18 volumio volumio[20412]: info: Starting Shairport Sync
Feb 19 01:25:18 volumio volumio[20412]: info: Loading plugin "last_100"...
Feb 19 01:25:18 volumio volumio[20412]: info: Loading plugin "webradio"...
Feb 19 01:25:18 volumio volumio[20412]: info: Loading plugin "i2s_dacs"...
Feb 19 01:25:18 volumio volumio[20412]: info: Loading plugin "volumiodiscovery"...
Feb 19 01:25:18 volumio volumio[20412]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 19 01:25:18 volumio volumio[20412]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 19 01:25:18 volumio node[20412]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 19 01:25:18 volumio volumio[20412]: *** WARNING *** For more information see
Feb 19 01:25:18 volumio volumio[20412]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 19 01:25:18 volumio volumio[20412]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 19 01:25:18 volumio volumio[20412]: *** WARNING *** For more information see
Feb 19 01:25:18 volumio node[20412]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 19 01:25:18 volumio node[20412]: *** WARNING *** For more information see
Feb 19 01:25:18 volumio node[20412]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 19 01:25:18 volumio node[20412]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 19 01:25:18 volumio node[20412]: *** WARNING *** For more information see
Feb 19 01:25:18 volumio volumio[20412]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 19 01:25:18 volumio volumio[20412]: info: Discovery: Started advertising with name: Volumio
Feb 19 01:25:18 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 19 01:25:18 volumio volumio[20412]: info: Loading plugin "spop"...
Feb 19 01:25:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Feb 19 01:25:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:19 volumio go-librespot[20492]: go-librespot daemon starting...
Feb 19 01:25:19 volumio go-librespot[20493]: time="2026-02-19T01:25:19+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:19 volumio go-librespot[20493]: time="2026-02-19T01:25:19+07:00" level=debug msg="app state loaded"
Feb 19 01:25:19 volumio go-librespot[20493]: time="2026-02-19T01:25:19+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:19 volumio go-librespot[20493]: time="2026-02-19T01:25:19+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 19 01:25:19 volumio go-librespot[20493]: time="2026-02-19T01:25:19+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 19 01:25:19 volumio go-librespot[20493]: time="2026-02-19T01:25:19+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 19 01:25:19 volumio go-librespot[20493]: time="2026-02-19T01:25:19+07:00" level=info msg="zeroconf server listening on port 35761"
Feb 19 01:25:20 volumio go-librespot[20493]: time="2026-02-19T01:25:20+07:00" level=debug msg="obtained new client token: AACLEIDVlzLMRhTfMy3/40WHRYlt56IECgIVcReEZ1zGONaAaHLmzjcj6xSu7aatbcmKxbuteeIrYKaf2Wi4kcILLW932caqUJtiQ3jGwbOvbE8ii1H+OKnOuW9PD0WOf15w6faqp2SYViNBXn1MGiotq7PeAptIF6J5jh8PQsAs2S1uxhR1WH79hZPU8xfehJoO1MuZQVtw9zX/L4wqu1owzuQZPLktBdLb/5MUvD+onxqdOcIebX0="
Feb 19 01:25:20 volumio go-librespot[20493]: time="2026-02-19T01:25:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:20 volumio go-librespot[20493]: time="2026-02-19T01:25:20+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:20 volumio go-librespot[20493]: time="2026-02-19T01:25:20+07:00" level=debug msg="completed challenge"
Feb 19 01:25:20 volumio go-librespot[20493]: time="2026-02-19T01:25:20+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 19 01:25:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:20 volumio volumio[20412]: info: Loading plugin "ytcr"...
Feb 19 01:25:23 volumio volumio[20412]: info: Loading plugin "ytmusic"...
Feb 19 01:25:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Feb 19 01:25:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:23 volumio go-librespot[20501]: go-librespot daemon starting...
Feb 19 01:25:23 volumio go-librespot[20502]: time="2026-02-19T01:25:23+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:23 volumio go-librespot[20502]: time="2026-02-19T01:25:23+07:00" level=debug msg="app state loaded"
Feb 19 01:25:23 volumio go-librespot[20502]: time="2026-02-19T01:25:23+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:24 volumio volumio-remote-updater[25144]: [2026-02-19 01:25:24] [connect] Successful connection
Feb 19 01:25:24 volumio go-librespot[20502]: time="2026-02-19T01:25:24+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 19 01:25:24 volumio go-librespot[20502]: time="2026-02-19T01:25:24+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 19 01:25:24 volumio go-librespot[20502]: time="2026-02-19T01:25:24+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 19 01:25:24 volumio go-librespot[20502]: time="2026-02-19T01:25:24+07:00" level=info msg="zeroconf server listening on port 33951"
Feb 19 01:25:24 volumio go-librespot[20502]: time="2026-02-19T01:25:24+07:00" level=debug msg="obtained new client token: AAAZKEAoLkvl6aMTxW/5S49HqOZy+QX2PvV3m0u99K1C4H8vcHmYSgA0y+0z7EPqDEugDT9aaVs7eehVVjKrPJFWRdquitGFVz+Z83ZOJ6AOEcajJwT4sTMvs+sYZUQQf9b8fkd01LjGh+BYnqxpqowH+fgG4VzgUG3fchVmPkwAs/zhQV/h4XO46tBo1YhtEhMtvDeXarIRDwpbjF56h191+TsC9oDxloLuyiiD3oUK34vZWrqlz87rFw=="
Feb 19 01:25:24 volumio go-librespot[20502]: time="2026-02-19T01:25:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:24 volumio volumio[20412]: info: Loading plugin "outputs"...
Feb 19 01:25:24 volumio volumio[20412]: info: Loading plugin "albumart"...
Feb 19 01:25:24 volumio go-librespot[20502]: time="2026-02-19T01:25:24+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:24 volumio go-librespot[20502]: time="2026-02-19T01:25:24+07:00" level=debug msg="completed challenge"
Feb 19 01:25:24 volumio volumio[20412]: info: Plugin example_plugin is not enabled
Feb 19 01:25:24 volumio volumio[20412]: info: Loading plugin "inputs"...
Feb 19 01:25:24 volumio volumio[20412]: info: Loading plugin "updater_comm"...
Feb 19 01:25:24 volumio go-librespot[20502]: time="2026-02-19T01:25:24+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 19 01:25:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:24 volumio volumio[20412]: info: Plugin mpdemulation is not enabled
Feb 19 01:25:24 volumio volumio[20412]: info: Loading plugin "rest_api"...
Feb 19 01:25:24 volumio volumio[20412]: info: Loading plugin "websocket"...
Feb 19 01:25:25 volumio volumio[20412]: info: Starting Socket.io Server version 1.7.4
Feb 19 01:25:25 volumio volumio[20412]: info: Loading plugin "RoonBridge"...
Feb 19 01:25:25 volumio volumio[20412]: info: Applying required configuration parameters for plugin RoonBridge
Feb 19 01:25:25 volumio volumio[20412]: info: Loading i18n strings for locale en
Feb 19 01:25:25 volumio volumio[20412]: Updating browse sources language
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::initPlayerControls
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 19 01:25:25 volumio volumio[20524]: Forking 3 albumart workers
Feb 19 01:25:25 volumio volumio[20412]: Express server listening on port 3000
Feb 19 01:25:25 volumio volumio[20412]: [Metrics] WebUI: 16s 230.15ms
Feb 19 01:25:25 volumio volumio[20412]: info: CoreStateMachine::resetVolumioState
Feb 19 01:25:25 volumio volumio[20412]: info: CoreStateMachine::getcurrentVolume
Feb 19 01:25:25 volumio volumio[20412]: info: CoreCommandRouter::volumioRetrievevolume
Feb 19 01:25:25 volumio sudo[20566]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 19 01:25:25 volumio sudo[20566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:25 volumio sudo[20568]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 19 01:25:26 volumio sudo[20568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:26 volumio sudo[20566]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:26 volumio sudo[20568]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:26 volumio volumio[20412]: info: Volumio Network Manager: Network status updated: 1
Feb 19 01:25:26 volumio volumio[20412]: info: VolumeController:: Volume=100 Mute =false
Feb 19 01:25:26 volumio volumio[20412]: info: CoreStateMachine::pushState
Feb 19 01:25:26 volumio volumio[20412]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:26 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 19 01:25:26 volumio volumio[20412]: info: CoreCommandRouter::volumioPushState
Feb 19 01:25:26 volumio volumio[20412]: info: CoreStateMachine::updateTrackBlock
Feb 19 01:25:26 volumio volumio[20412]: info: CorePlayQueue::getTrackBlock
Feb 19 01:25:26 volumio volumio[20412]: info: CoreCommandRouter::volumioRetrievevolume
Feb 19 01:25:26 volumio volumio-remote-updater[25144]: [2026-02-19 01:25:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771439124 101
Feb 19 01:25:26 volumio volumio[20412]: 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 19 01:25:26 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:26 volumio volumio[20412]: info: Reloading queue from file
Feb 19 01:25:26 volumio volumio[20412]: info: CoreStateMachine::setRepeat null single undefined
Feb 19 01:25:26 volumio volumio[20412]: info: CoreStateMachine::pushState
Feb 19 01:25:26 volumio volumio[20412]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:26 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 19 01:25:26 volumio volumio[20412]: info: CoreCommandRouter::volumioPushState
Feb 19 01:25:26 volumio volumio[20412]: info: CoreStateMachine::setRandom null
Feb 19 01:25:26 volumio volumio[20412]: info: CoreStateMachine::pushState
Feb 19 01:25:26 volumio volumio[20412]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:26 volumio volumio[20412]: info: CoreCommandRouter::volumioPushState
Feb 19 01:25:26 volumio volumio[20412]: info: Setting Device type: Raspberry PI
Feb 19 01:25:26 volumio volumio[20412]: info: Completed loading Core Plugins
Feb 19 01:25:26 volumio volumio[20412]: info: Preparing to generate the ALSA configuration file
Feb 19 01:25:26 volumio volumio[20412]: info: VolumeController:: Volume=100 Mute =false
Feb 19 01:25:26 volumio volumio[20412]: info: CoreStateMachine::pushState
Feb 19 01:25:26 volumio volumio[20412]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:26 volumio volumio[20412]: info: CoreCommandRouter::volumioPushState
Feb 19 01:25:26 volumio volumio[20412]: info: Asound.conf file unchanged, so no further update is needed
Feb 19 01:25:26 volumio volumio[20412]: info: Output device has changed, restarting MPD
Feb 19 01:25:26 volumio sudo[20585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 19 01:25:26 volumio sudo[20585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:26 volumio volumio[20412]: info: Output device has changed, restarting Shairport Sync
Feb 19 01:25:26 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:26 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:26 volumio sudo[20587]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 19 01:25:26 volumio sudo[20587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:26 volumio sudo[20587]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:26 volumio sudo[20589]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 19 01:25:26 volumio sudo[20589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:26 volumio sudo[20585]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:27 volumio volumio[20412]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 19 01:25:27 volumio volumio[20412]: info: ___________ START PLUGINS ___________
Feb 19 01:25:27 volumio volumio[20412]: info: ControllerMpd::onStart: Initializing MPD
Feb 19 01:25:27 volumio volumio[20412]: info: Creating MPD Configuration file
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:25:27 volumio volumio[20412]: info: [1771439127081] CoreMusicLibrary::Adding element Media Servers
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:25:27 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 19 01:25:27 volumio sudo[20600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 19 01:25:27 volumio sudo[20600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:27 volumio sudo[20598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 19 01:25:27 volumio sudo[20598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:27 volumio volumio[20412]: info: UPNP Browser: Client initialized successfully
Feb 19 01:25:27 volumio sudo[20598]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:27 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 19 01:25:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 19 01:25:27 volumio systemd[1]: mpd.service: Consumed 7.227s CPU time.
Feb 19 01:25:27 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 19 01:25:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 19 01:25:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 19 01:25:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 19 01:25:27 volumio volumio[20412]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:27 volumio volumio[20412]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:25:27 volumio volumio[20412]: info: [1771439127486] CoreMusicLibrary::Adding element Last_100
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:25:27 volumio volumio[20412]: info: [1771439127527] CoreMusicLibrary::Adding element Webradio
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 19 01:25:27 volumio volumio[20412]: info: Initializing BBC Radios
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Feb 19 01:25:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:27 volumio volumio[20412]: info: Creating Spotify config file
Feb 19 01:25:27 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:27 volumio sudo[20608]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 19 01:25:27 volumio sudo[20608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 19 01:25:27 volumio sudo[20608]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:27 volumio go-librespot[20626]: go-librespot daemon starting...
Feb 19 01:25:27 volumio go-librespot[20628]: time="2026-02-19T01:25:27+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:28 volumio go-librespot[20628]: time="2026-02-19T01:25:28+07:00" level=info msg="zeroconf server listening on port 38427"
Feb 19 01:25:29 volumio volumio[20412]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:25:29 volumio volumio[20412]: info: [1771439129151] CoreMusicLibrary::Adding element YouTube Music
Feb 19 01:25:29 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:25:29 volumio volumio[20412]: Cannot find translation for source YouTube Music
Feb 19 01:25:29 volumio volumio[20412]: info: Volumio Calling Home
Feb 19 01:25:29 volumio volumio[20539]: Starting albumart workers
Feb 19 01:25:29 volumio volumio[20535]: Starting albumart workers
Feb 19 01:25:29 volumio sudo[20637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 19 01:25:29 volumio sudo[20637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:29 volumio sudo[20637]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:29 volumio volumio[20538]: Starting albumart workers
Feb 19 01:25:29 volumio volumio[20412]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 19 01:25:29 volumio volumio[20412]: info: Discovery: Found device Volumio
Feb 19 01:25:29 volumio volumio[20412]: info: CoreCommandRouter::volumioGetState
Feb 19 01:25:29 volumio volumio[20412]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:29 volumio volumio[20412]: info: MPD Permissions set
Feb 19 01:25:29 volumio volumio[20412]: info: MPD Permissions set
Feb 19 01:25:29 volumio volumio[20412]: info: Upmpdcli Daemon Started
Feb 19 01:25:29 volumio volumio[20412]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7
Feb 19 01:25:29 volumio volumio[20412]: info: Discovery: Found device Volumio
Feb 19 01:25:29 volumio volumio[20412]: info: CoreCommandRouter::volumioGetState
Feb 19 01:25:29 volumio volumio[20412]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:29 volumio volumio[20412]: info: Spotify config file written
Feb 19 01:25:30 volumio volumio[20412]: 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 19 01:25:30 volumio volumio[20412]: info: Volumio called home
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio sudo[20643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 19 01:25:30 volumio sudo[20643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 19 01:25:30 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 19 01:25:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:30 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 19 01:25:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:30 volumio go-librespot[20655]: go-librespot daemon starting...
Feb 19 01:25:30 volumio volumio[20412]: info: No need to fix Spotify hosts
Feb 19 01:25:30 volumio sudo[20643]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:30 volumio go-librespot[20656]: time="2026-02-19T01:25:30+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:30 volumio go-librespot[20656]: time="2026-02-19T01:25:30+07:00" level=debug msg="app state loaded"
Feb 19 01:25:30 volumio go-librespot[20656]: time="2026-02-19T01:25:30+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:31 volumio go-librespot[20656]: time="2026-02-19T01:25: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 19 01:25:31 volumio go-librespot[20656]: time="2026-02-19T01:25:31+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 19 01:25:31 volumio go-librespot[20656]: time="2026-02-19T01:25:31+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 19 01:25:31 volumio go-librespot[20656]: time="2026-02-19T01:25:31+07:00" level=info msg="zeroconf server listening on port 42581"
Feb 19 01:25:31 volumio go-librespot[20656]: time="2026-02-19T01:25:31+07:00" level=debug msg="obtained new client token: AABPuR2Kvq3hQDb9JXBIGvWlEkVaj5oSuxnx+EbzFUtN5lpozz5AaP9lhN18NVKPFTPdjugoKgZ8p5DGS0+v6lQFqSn8YCx0LzRcLd91gIp3FB24Gabpyro8GCcxFcoS0cmcRueunth94q655sRfAGQGbI36bn4U1AyYbA2hfpWa/FIyry4Na4AKHL61Frj8y2ccLRx/9m/XajBsL/cauYo6IjQzz5DBtjTBmLjJLidPRcaAMxFANchp7g=="
Feb 19 01:25:31 volumio go-librespot[20656]: time="2026-02-19T01:25:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:31 volumio go-librespot[20656]: time="2026-02-19T01:25:31+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:31 volumio go-librespot[20656]: time="2026-02-19T01:25:31+07:00" level=debug msg="completed challenge"
Feb 19 01:25:31 volumio volumio[20412]: info: Starting Shairport Sync
Feb 19 01:25:31 volumio go-librespot[20656]: time="2026-02-19T01:25: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 19 01:25:31 volumio volumio[20412]: info: Starting Shairport Sync
Feb 19 01:25:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:31 volumio volumio[20412]: info: Starting Shairport Sync
Feb 19 01:25:31 volumio sudo[20677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 19 01:25:31 volumio sudo[20677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:31 volumio sudo[20681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 19 01:25:31 volumio sudo[20681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:32 volumio sudo[20679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 19 01:25:32 volumio sudo[20679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 19 01:25:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 19 01:25:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 19 01:25:32 volumio systemd[1]: shairport-sync.service: Consumed 2.374s CPU time.
Feb 19 01:25:32 volumio volumio[20412]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 19 01:25:32 volumio volumio[20412]: SPOTIFY: BQBtNqM-uCyVNzRzklE-CjjERlNb8ISe3wJR6m_Tf2a5OQhtI_Nk1fcJ8WLht0iXouzj4v_zk2HYEvbophqovcDbQcJNLD4kDFB1Y0_lJeMuMVKdhmm3131S70axI77XjuzVm2BxonwjMql4cpjvMYzVWhkE-BrA21R4xFIxMEhjeIFbF_VEIEDNll9yAzdV4fTymHpDzAtblAhrFOjEqVOCdvo9I3CdLR7R2kCW0OtZLHpHzWIzjqVs0ua8Quq6KFs0VEMx8u7wqZKGdUwFT8K_j54oSnrc71DsiXOvPnzQ0mmEEShN9Qk_
Feb 19 01:25:32 volumio volumio[20412]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 19 01:25:32 volumio volumio[20412]: info: New Spotify access token = BQBtNqM-uCyVNzRzklE-CjjERlNb8ISe3wJR6m_Tf2a5OQhtI_Nk1fcJ8WLht0iXouzj4v_zk2HYEvbophqovcDbQcJNLD4kDFB1Y0_lJeMuMVKdhmm3131S70axI77XjuzVm2BxonwjMql4cpjvMYzVWhkE-BrA21R4xFIxMEhjeIFbF_VEIEDNll9yAzdV4fTymHpDzAtblAhrFOjEqVOCdvo9I3CdLR7R2kCW0OtZLHpHzWIzjqVs0ua8Quq6KFs0VEMx8u7wqZKGdUwFT8K_j54oSnrc71DsiXOvPnzQ0mmEEShN9Qk_
Feb 19 01:25:32 volumio volumio[20412]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 19 01:25:32 volumio volumio[20412]: info: CoreCommandRouter::volumioGetState
Feb 19 01:25:32 volumio volumio[20412]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 19 01:25:32 volumio sudo[20677]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:32 volumio sudo[20681]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:32 volumio volumio[20412]: info: Shairport-Sync Started
Feb 19 01:25:32 volumio volumio[20412]: Error adding Membership: Error: addMembership EINVAL
Feb 19 01:25:32 volumio volumio[20412]: info: Shairport-Sync Started
Feb 19 01:25:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 19 01:25:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 19 01:25:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 19 01:25:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 19 01:25:32 volumio sudo[20679]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:32 volumio volumio[20412]: info: Shairport-Sync Started
Feb 19 01:25:32 volumio volumio[20412]: 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 19 01:25:32 volumio volumio[20412]: info: Spotify Successfully logged in
Feb 19 01:25:32 volumio volumio[20412]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 19 01:25:32 volumio volumio[20412]: info: [1771439132816] CoreMusicLibrary::Adding element Spotify
Feb 19 01:25:32 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 19 01:25:32 volumio volumio[20412]: Cannot find translation for source YouTube Music
Feb 19 01:25:32 volumio volumio[20412]: Cannot find translation for source Spotify
Feb 19 01:25:33 volumio volumio[20412]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 19 01:25:33 volumio volumio[20412]: info: CoreCommandRouter::volumioRetrievevolume
Feb 19 01:25:33 volumio volumio[20412]: info: VolumeController:: Volume=100 Mute =false
Feb 19 01:25:33 volumio volumio[20412]: info: CoreCommandRouter::volumioGetState
Feb 19 01:25:33 volumio volumio[20412]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:33 volumio volumio[20412]: info: CoreStateMachine::pushState
Feb 19 01:25:33 volumio volumio[20412]: info: CorePlayQueue::getTrack 0
Feb 19 01:25:33 volumio volumio[20412]: info: CoreCommandRouter::volumioPushState
Feb 19 01:25:34 volumio volumio[20412]: info: go-librespot daemon successfully initialized
Feb 19 01:25:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 19 01:25:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:35 volumio go-librespot[20724]: go-librespot daemon starting...
Feb 19 01:25:35 volumio go-librespot[20725]: time="2026-02-19T01:25:35+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:35 volumio go-librespot[20725]: time="2026-02-19T01:25:35+07:00" level=debug msg="app state loaded"
Feb 19 01:25:35 volumio go-librespot[20725]: time="2026-02-19T01:25:35+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:35 volumio mpd[20634]: 2026-02-19T01:25:35 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 19 01:25:35 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 19 01:25:35 volumio sudo[20589]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:35 volumio sudo[20600]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:35 volumio volumio[20412]: error: MPD error: The expression evaluated to a falsy value:
Feb 19 01:25:35 volumio volumio[20412]: assert.ok(self.idling)
Feb 19 01:25:35 volumio volumio[20412]: error: The expression evaluated to a falsy value:
Feb 19 01:25:35 volumio volumio[20412]: assert.ok(self.idling)
Feb 19 01:25:35 volumio go-librespot[20725]: time="2026-02-19T01:25: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 19 01:25:35 volumio go-librespot[20725]: time="2026-02-19T01:25:35+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 19 01:25:35 volumio go-librespot[20725]: time="2026-02-19T01:25:35+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 19 01:25:35 volumio volumio[20412]: info: MPD running with PID20634
Feb 19 01:25:35 volumio volumio[20412]: ,establishing connection
Feb 19 01:25:35 volumio volumio[20412]: error: updateQueue error: null
Feb 19 01:25:35 volumio go-librespot[20725]: time="2026-02-19T01:25:35+07:00" level=info msg="zeroconf server listening on port 34625"
Feb 19 01:25:35 volumio volumio[20412]: info: Completed starting Core Plugins
Feb 19 01:25:35 volumio volumio[20412]: info: -------------------------------------------
Feb 19 01:25:35 volumio volumio[20412]: info: ----- MyVolumio plugins startup ----
Feb 19 01:25:35 volumio volumio[20412]: info: -------------------------------------------
Feb 19 01:25:35 volumio volumio[20412]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 19 01:25:35 volumio volumio[20412]: error: updateQueue error: null
Feb 19 01:25:35 volumio go-librespot[20725]: time="2026-02-19T01:25:35+07:00" level=debug msg="obtained new client token: AADVpT337Pv62/Df1AkqaJ+9gE2IKRBaWLGuzKUYTyOcUc4P/Vtu7/tFpsSj3/1PyooA56iJNPqeHLLaAfKRLsGGzJ9RAVzikdaCl8cRW7nAnvxUScs3JB0A3lqcrLxbKNcvpBLRvTvYEmgEW18R0JSd1QLJedBG8+o/Gb9j0pY5BvVG+NScHrZ8IimalXXYBNC1DkL1QYPCI9NNtqv1xWzM1WacEEYBZ3PQtIWxDgkM3bpYa4iH4rPP5Q=="
Feb 19 01:25:36 volumio go-librespot[20725]: time="2026-02-19T01:25:36+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 19 01:25:36 volumio go-librespot[20725]: time="2026-02-19T01:25:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 19 01:25:36 volumio go-librespot[20725]: time="2026-02-19T01:25:36+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:36 volumio go-librespot[20725]: time="2026-02-19T01:25:36+07:00" level=debug msg="completed challenge"
Feb 19 01:25:36 volumio go-librespot[20725]: time="2026-02-19T01:25: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 19 01:25:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:37 volumio volumio[20412]: info: Initializing connection to go-librespot Websocket
Feb 19 01:25:37 volumio volumio[20412]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 19 01:25:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 19 01:25:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:39 volumio go-librespot[20737]: go-librespot daemon starting...
Feb 19 01:25:39 volumio go-librespot[20738]: time="2026-02-19T01:25:39+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:39 volumio go-librespot[20738]: time="2026-02-19T01:25:39+07:00" level=debug msg="app state loaded"
Feb 19 01:25:39 volumio go-librespot[20738]: time="2026-02-19T01:25:39+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:40 volumio go-librespot[20738]: time="2026-02-19T01:25: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-gew1.spotify.com:80]"
Feb 19 01:25:40 volumio go-librespot[20738]: time="2026-02-19T01:25:40+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 19 01:25:40 volumio go-librespot[20738]: time="2026-02-19T01:25:40+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 19 01:25:40 volumio go-librespot[20738]: time="2026-02-19T01:25:40+07:00" level=info msg="zeroconf server listening on port 45445"
Feb 19 01:25:40 volumio go-librespot[20738]: time="2026-02-19T01:25:40+07:00" level=debug msg="obtained new client token: AACUhSS/KjXW16PThrfw0Ga4eoYGdZPGNIlaIm+GCCo3rUzpUcQUvgiJZn6PgaO1QHfKN9f7UwSjV1mNXIEOOsdEERfDqwEQWe57cQao2xbSNSeuCM27LGAAAYLA7LJoiqTCt4HLXBgS6w7X+6VuJJYjha822gn1FMllyUuylJeHNw6pIuPCGn2YAdN5sbGaN+xTSA/fHeaozng7DUXYmf3MLjObkPlq7GKrIcNr4R9dl0hF0y2s90VLFA=="
Feb 19 01:25:40 volumio go-librespot[20738]: time="2026-02-19T01:25:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:40 volumio volumio[20412]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Feb 19 01:25:40 volumio go-librespot[20738]: time="2026-02-19T01:25:40+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:40 volumio go-librespot[20738]: time="2026-02-19T01:25:40+07:00" level=debug msg="completed challenge"
Feb 19 01:25:40 volumio go-librespot[20738]: time="2026-02-19T01:25: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 19 01:25:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:40 volumio volumio[20412]: info: Initializing connection to go-librespot Websocket
Feb 19 01:25:40 volumio volumio[20412]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 19 01:25:43 volumio volumio[20412]: info: Initializing connection to go-librespot Websocket
Feb 19 01:25:43 volumio volumio[20412]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 19 01:25:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 19 01:25:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:43 volumio go-librespot[20745]: go-librespot daemon starting...
Feb 19 01:25:43 volumio go-librespot[20747]: time="2026-02-19T01:25:43+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:43 volumio go-librespot[20747]: time="2026-02-19T01:25:43+07:00" level=debug msg="app state loaded"
Feb 19 01:25:43 volumio go-librespot[20747]: time="2026-02-19T01:25:43+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:44 volumio go-librespot[20747]: time="2026-02-19T01:25:44+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 19 01:25:44 volumio go-librespot[20747]: time="2026-02-19T01:25:44+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 19 01:25:44 volumio go-librespot[20747]: time="2026-02-19T01:25:44+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 19 01:25:44 volumio go-librespot[20747]: time="2026-02-19T01:25:44+07:00" level=info msg="zeroconf server listening on port 39621"
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 19 01:25:44 volumio volumio[20412]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 19 01:25:44 volumio volumio[20412]: info: Adding plugin multiroom to MyMusic Plugins
Feb 19 01:25:44 volumio volumio[20412]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 19 01:25:44 volumio volumio[20412]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 19 01:25:44 volumio volumio[20412]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 19 01:25:44 volumio volumio[20412]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 19 01:25:44 volumio volumio[20412]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 19 01:25:44 volumio volumio[20412]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 19 01:25:44 volumio go-librespot[20747]: time="2026-02-19T01:25:44+07:00" level=debug msg="obtained new client token: AAALj49pr/yGIq16fTqo4WcCS+l5whCjUA/0TZcO9O5oHD8I1KwSPyY9NLwr5Iv7KDefivFgbRVrEqlAeaZMFVJQsZU7C11VopYug4khAlsI9u1JilGzOMxWFHke0IN61OxEh/DCUFW9k7SDObL4UfKI+kpwd2TOhBuEHWN57JNx8zgwvvTxhRQNWQe296f0pqPs2BSZRkmI+JhGOQR56kJqvpyoce61J/IPn7FT+QAScyrgygOAFOgsuA=="
Feb 19 01:25:44 volumio go-librespot[20747]: time="2026-02-19T01:25:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:44 volumio go-librespot[20747]: time="2026-02-19T01:25:44+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:44 volumio go-librespot[20747]: time="2026-02-19T01:25:44+07:00" level=debug msg="completed challenge"
Feb 19 01:25:44 volumio go-librespot[20747]: time="2026-02-19T01:25:44+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 19 01:25:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:46 volumio volumio[20412]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 19 01:25:46 volumio volumio[20412]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 19 01:25:46 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:46 volumio volumio[20412]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 19 01:25:46 volumio volumio[20412]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 19 01:25:46 volumio volumio[20412]: info: MyVolumio login type: Token
Feb 19 01:25:46 volumio volumio[20412]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 19 01:25:46 volumio volumio[20412]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 19 01:25:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 19 01:25:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:48 volumio go-librespot[20769]: go-librespot daemon starting...
Feb 19 01:25:48 volumio go-librespot[20770]: time="2026-02-19T01:25:48+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:48 volumio go-librespot[20770]: time="2026-02-19T01:25:48+07:00" level=debug msg="app state loaded"
Feb 19 01:25:48 volumio go-librespot[20770]: time="2026-02-19T01:25:48+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:48 volumio volumio[20412]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 19 01:25:48 volumio volumio[20412]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 19 01:25:48 volumio volumio[20412]: info: Streaming services startup
Feb 19 01:25:48 volumio volumio[20412]: info: Starting Streaming Daemon
Feb 19 01:25:48 volumio sudo[20777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 19 01:25:48 volumio volumio[20412]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 19 01:25:48 volumio sudo[20777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:48 volumio sudo[20777]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:48 volumio volumio[20412]: info: Initializing connection to go-librespot Websocket
Feb 19 01:25:48 volumio volumio[20412]: error: Cannot start Volumio Streaming Daemon
Feb 19 01:25:48 volumio volumio[20412]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 19 01:25:48 volumio volumio[20412]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 19 01:25:48 volumio go-librespot[20770]: time="2026-02-19T01:25:48+07:00" level=debug msg="new websocket client"
Feb 19 01:25:48 volumio volumio[20412]: info: Connection to go-librespot Websocket established
Feb 19 01:25:48 volumio go-librespot[20770]: time="2026-02-19T01:25:48+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 19 01:25:48 volumio go-librespot[20770]: time="2026-02-19T01:25:48+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 19 01:25:48 volumio go-librespot[20770]: time="2026-02-19T01:25:48+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 19 01:25:48 volumio go-librespot[20770]: time="2026-02-19T01:25:48+07:00" level=info msg="zeroconf server listening on port 35121"
Feb 19 01:25:48 volumio go-librespot[20770]: time="2026-02-19T01:25:48+07:00" level=debug msg="obtained new client token: AAAkAlCqG+/GNbMtOKmqZlPDpPXr2caKBepW9DBrl6KZpWfd/Cm9ktN3gK9WlZPkLir+SKEK1Td+qpm3XUA31Z3X+d/cFzae7WtjhpxSIc8WfIDerbYiq5F6+Aszju0uFfhMRZG0y5gwRHHnAA+qEOenPUvbYdh4MKBWJXC9RZyineFv+Gmj6yoVj8qqs/Rctfu6RpvlVUaScigBD54h0Uq21CV4GQRyZ8Y6f/8hczeI4F7nQq9q+ySwuA=="
Feb 19 01:25:49 volumio go-librespot[20770]: time="2026-02-19T01:25:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:49 volumio go-librespot[20770]: time="2026-02-19T01:25:49+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:49 volumio go-librespot[20770]: time="2026-02-19T01:25:49+07:00" level=debug msg="completed challenge"
Feb 19 01:25:49 volumio go-librespot[20770]: time="2026-02-19T01:25:49+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 19 01:25:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 19 01:25:49 volumio volumio[20412]: info: Connection to go-librespot Websocket closed
Feb 19 01:25:50 volumio volumio[20412]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 19 01:25:50 volumio volumio[20412]: info: MyVolumio token set successfully
Feb 19 01:25:50 volumio volumio[20412]: info: MYVOLUMIO: Adding device
Feb 19 01:25:50 volumio volumio[20412]: info: MYVOLUMIO: Evaluating Server
Feb 19 01:25:51 volumio volumio[20412]: info: MyVolumio status changed
Feb 19 01:25:51 volumio volumio[20412]: info: Streaming services startup
Feb 19 01:25:51 volumio volumio[20412]: info: Starting Streaming Daemon
Feb 19 01:25:51 volumio volumio[20412]: info: Removing browser output: myVolumio user plan is not superstar
Feb 19 01:25:51 volumio volumio[20412]: info: Removing audio output:
Feb 19 01:25:51 volumio volumio[20412]: info: Stoppping Tunnel 1
Feb 19 01:25:51 volumio sudo[20807]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 19 01:25:51 volumio sudo[20807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:51 volumio sudo[20810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 19 01:25:51 volumio sudo[20810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:51 volumio sudo[20807]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:51 volumio volumio[20412]: error: Cannot start Volumio Streaming Daemon
Feb 19 01:25:51 volumio volumio[20412]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 19 01:25:51 volumio volumio[20412]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 19 01:25:51 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 19 01:25:51 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 19 01:25:51 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 19 01:25:51 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 19 01:25:51 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 19 01:25:51 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 19 01:25:51 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 19 01:25:51 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 19 01:25:51 volumio sudo[20810]: pam_unix(sudo:session): session closed for user root
Feb 19 01:25:51 volumio volumio[20412]: info: Getting Spotify volume
Feb 19 01:25:51 volumio volumio[20412]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 19 01:25:51 volumio volumio[20412]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 19 01:25:51 volumio volumio[20412]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 19 01:25:51 volumio volumio[20412]: errno: -111,
Feb 19 01:25:51 volumio volumio[20412]: code: 'ECONNREFUSED',
Feb 19 01:25:51 volumio volumio[20412]: syscall: 'connect',
Feb 19 01:25:51 volumio volumio[20412]: address: '127.0.0.1',
Feb 19 01:25:51 volumio volumio[20412]: port: 9879,
Feb 19 01:25:51 volumio volumio[20412]: response: undefined
Feb 19 01:25:51 volumio volumio[20412]: }
Feb 19 01:25:51 volumio volumio[20412]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 19 01:25:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 19 01:25:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 19 01:25:52 volumio go-librespot[20824]: go-librespot daemon starting...
Feb 19 01:25:52 volumio go-librespot[20825]: time="2026-02-19T01:25:52+07:00" level=info msg="running go-librespot 0.4.0"
Feb 19 01:25:52 volumio go-librespot[20825]: time="2026-02-19T01:25:52+07:00" level=debug msg="app state loaded"
Feb 19 01:25:52 volumio go-librespot[20825]: time="2026-02-19T01:25:52+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 19 01:25:52 volumio go-librespot[20825]: time="2026-02-19T01:25:52+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 19 01:25:52 volumio go-librespot[20825]: time="2026-02-19T01:25:52+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 19 01:25:52 volumio go-librespot[20825]: time="2026-02-19T01:25:52+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 19 01:25:52 volumio go-librespot[20825]: time="2026-02-19T01:25:52+07:00" level=info msg="zeroconf server listening on port 38327"
Feb 19 01:25:53 volumio sudo[20834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-19 01:24'
Feb 19 01:25:53 volumio sudo[20834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 19 01:25:53 volumio go-librespot[20825]: time="2026-02-19T01:25:53+07:00" level=debug msg="obtained new client token: AAAXvb4TjHade8b6XufBd5jZWKmgJl1i2S2/fEAqcxBb5Qj7wu1tQGdWJxth4AQdF1OhgX/nqnxizTnhdo+OQV/0VvwLkr2wrNCUFfWlEP79YZKg8IlzOIw/ZqD3QSM7EhZv9iSqSTtDvo1TC38U03hqZRpGRHE+xgyDTiSWbksaGhF9/slCn+BN9oeiDSYDsocAEUgncUmc1bgHYE/yk0nZUXDe1SrS6aueUTwyoR1Lr+HPySgNh7c="
Feb 19 01:25:53 volumio go-librespot[20825]: time="2026-02-19T01:25:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 19 01:25:53 volumio go-librespot[20825]: time="2026-02-19T01:25:53+07:00" level=debug msg="completed keyexchange"
Feb 19 01:25:53 volumio go-librespot[20825]: time="2026-02-19T01:25:53+07:00" level=debug msg="completed challenge"
Feb 19 01:25:53 volumio go-librespot[20825]: time="2026-02-19T01:25:53+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 19 01:25:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:25:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
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"