Feb 10 15:08:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 10 15:08:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:00 volumio go-librespot[5153]: go-librespot daemon starting... Feb 10 15:08:00 volumio volumio[5075]: info: Starting UPNP Browser Feb 10 15:08:00 volumio volumio[5075]: info: Loading plugin "alarm-clock"... Feb 10 15:08:00 volumio go-librespot[5154]: time="2026-02-10T15:08:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:00 volumio go-librespot[5154]: time="2026-02-10T15:08:00+07:00" level=debug msg="app state loaded" Feb 10 15:08:00 volumio go-librespot[5154]: time="2026-02-10T15:08:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:00 volumio volumio[5075]: info: Loading plugin "airplay_emulation"... Feb 10 15:08:01 volumio volumio[5075]: info: Starting Shairport Sync Feb 10 15:08:01 volumio volumio[5075]: info: Loading plugin "last_100"... Feb 10 15:08:01 volumio volumio[5075]: info: Loading plugin "webradio"... Feb 10 15:08:01 volumio volumio[5075]: info: Loading plugin "i2s_dacs"... Feb 10 15:08:01 volumio volumio[5075]: info: Loading plugin "volumiodiscovery"... Feb 10 15:08:01 volumio go-librespot[5154]: time="2026-02-10T15:08:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 15:08:01 volumio go-librespot[5154]: time="2026-02-10T15:08:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 15:08:01 volumio go-librespot[5154]: time="2026-02-10T15:08:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 15:08:01 volumio go-librespot[5154]: time="2026-02-10T15:08:01+07:00" level=info msg="zeroconf server listening on port 34487" Feb 10 15:08:01 volumio volumio[5075]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 15:08:01 volumio volumio[5075]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 15:08:01 volumio volumio[5075]: *** WARNING *** For more information see Feb 10 15:08:01 volumio volumio[5075]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 15:08:01 volumio volumio[5075]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 15:08:01 volumio volumio[5075]: *** WARNING *** For more information see Feb 10 15:08:01 volumio node[5075]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 15:08:01 volumio node[5075]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 15:08:01 volumio node[5075]: *** WARNING *** For more information see Feb 10 15:08:01 volumio node[5075]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 15:08:01 volumio node[5075]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 15:08:01 volumio node[5075]: *** WARNING *** For more information see Feb 10 15:08:01 volumio volumio[5075]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 15:08:01 volumio volumio[5075]: info: Discovery: Started advertising with name: Volumio Feb 10 15:08:01 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 15:08:01 volumio volumio[5075]: info: Loading plugin "spop"... Feb 10 15:08:01 volumio go-librespot[5154]: time="2026-02-10T15:08:01+07:00" level=debug msg="obtained new client token: AACJlF9JtGcndz6Mjvdl7ZfWxl6XUkaevQItAEI/hPZdAJ7WMTHNFqYRlZz0DL+YtMI85sEUIEaOQXKqgvlkDaxObDE9aQ+1TbX5+Dyt/8mL7jg2Psi4pVtB6vgnsyzxp37fcdkmpyLIg0TXIcyTOmws2IBIiTcOB/h7lr62t1tLMzBHVO0ajJs1M/P6lzMlvLB0+oZDzdV9zuOuzOaDTIQdxgfwJBdMcH/4vk5UzlN+b62jddtX4MZkHg==" Feb 10 15:08:01 volumio go-librespot[5154]: time="2026-02-10T15:08:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:01 volumio go-librespot[5154]: time="2026-02-10T15:08:01+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:01 volumio go-librespot[5154]: time="2026-02-10T15:08:01+07:00" level=debug msg="completed challenge" Feb 10 15:08:01 volumio go-librespot[5154]: time="2026-02-10T15:08:01+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 10 15:08:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:03 volumio volumio[5075]: info: Loading plugin "ytcr"... Feb 10 15:08:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 10 15:08:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:05 volumio go-librespot[5163]: go-librespot daemon starting... Feb 10 15:08:05 volumio go-librespot[5164]: time="2026-02-10T15:08:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:05 volumio go-librespot[5164]: time="2026-02-10T15:08:05+07:00" level=debug msg="app state loaded" Feb 10 15:08:05 volumio go-librespot[5164]: time="2026-02-10T15:08:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:05 volumio go-librespot[5164]: time="2026-02-10T15:08:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 15:08:05 volumio go-librespot[5164]: time="2026-02-10T15:08:05+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 10 15:08:05 volumio go-librespot[5164]: time="2026-02-10T15:08:05+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 10 15:08:05 volumio go-librespot[5164]: time="2026-02-10T15:08:05+07:00" level=info msg="zeroconf server listening on port 34685" Feb 10 15:08:05 volumio go-librespot[5164]: time="2026-02-10T15:08:05+07:00" level=debug msg="obtained new client token: AAB6h6OyH9Yj8pIAkPuv0SICccPYEC29BYihZl+VVLO1XqEKBQ98xSF3AEAmOiCeYBIp0LCLJYJNCpzeLxkXtL9LNoASCONH2TQNxToxwCfhG+z/2sEmOTtIlGRFPL8ZQ3NDOkgTyFVdxOvscWu3GNZGFQACvLqkC2fD7toDqVkX05sk2RgsZhPwEa6Iz5XGb7n/ThhTCZa5Zj64H/YplG05oR6qXBWsQlShUcAvsZAmmpZpXZM2aZIKow==" Feb 10 15:08:05 volumio volumio[5075]: info: Loading plugin "ytmusic"... Feb 10 15:08:06 volumio go-librespot[5164]: time="2026-02-10T15:08:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:06 volumio go-librespot[5164]: time="2026-02-10T15:08:06+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:06 volumio go-librespot[5164]: time="2026-02-10T15:08:06+07:00" level=debug msg="completed challenge" Feb 10 15:08:06 volumio go-librespot[5164]: time="2026-02-10T15:08:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 15:08:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:06 volumio volumio-remote-updater[643]: [2026-02-10 15:08:06] [connect] Successful connection Feb 10 15:08:07 volumio volumio[5075]: info: Loading plugin "outputs"... Feb 10 15:08:07 volumio volumio[5075]: info: Loading plugin "albumart"... Feb 10 15:08:07 volumio volumio[5075]: info: Plugin example_plugin is not enabled Feb 10 15:08:07 volumio volumio[5075]: info: Loading plugin "inputs"... Feb 10 15:08:07 volumio volumio[5075]: info: Loading plugin "updater_comm"... Feb 10 15:08:07 volumio volumio[5075]: info: Plugin mpdemulation is not enabled Feb 10 15:08:07 volumio volumio[5075]: info: Loading plugin "rest_api"... Feb 10 15:08:07 volumio volumio[5075]: info: Loading plugin "websocket"... Feb 10 15:08:07 volumio volumio[5075]: info: Starting Socket.io Server version 1.7.4 Feb 10 15:08:07 volumio volumio[5075]: info: Loading plugin "RoonBridge"... Feb 10 15:08:07 volumio volumio[5075]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 15:08:07 volumio volumio[5075]: info: Loading i18n strings for locale en Feb 10 15:08:08 volumio volumio[5075]: Updating browse sources language Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:08 volumio volumio[5185]: Forking 3 albumart workers Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::initPlayerControls Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 15:08:08 volumio volumio[5075]: Express server listening on port 3000 Feb 10 15:08:08 volumio volumio[5075]: [Metrics] WebUI: 16s 264.57ms Feb 10 15:08:08 volumio volumio[5075]: info: CoreStateMachine::resetVolumioState Feb 10 15:08:08 volumio volumio[5075]: info: CoreStateMachine::getcurrentVolume Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 15:08:08 volumio sudo[5230]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 15:08:08 volumio sudo[5230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:08 volumio sudo[5230]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:08 volumio sudo[5232]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 15:08:08 volumio sudo[5232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:08 volumio sudo[5232]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:08 volumio volumio[5075]: info: Volumio Network Manager: Network status updated: 1 Feb 10 15:08:08 volumio volumio[5075]: info: VolumeController:: Volume=100 Mute =false Feb 10 15:08:08 volumio volumio[5075]: info: CoreStateMachine::pushState Feb 10 15:08:08 volumio volumio[5075]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::volumioPushState Feb 10 15:08:08 volumio volumio[5075]: info: CoreStateMachine::updateTrackBlock Feb 10 15:08:08 volumio volumio[5075]: info: CorePlayQueue::getTrackBlock Feb 10 15:08:08 volumio volumio[5075]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 15:08:09 volumio volumio-remote-updater[643]: [2026-02-10 15:08:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770710886 101 Feb 10 15:08:09 volumio volumio[5075]: 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 10 15:08:09 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:09 volumio volumio[5075]: info: Reloading queue from file Feb 10 15:08:09 volumio volumio[5075]: info: CoreStateMachine::setRepeat null single undefined Feb 10 15:08:09 volumio volumio[5075]: info: CoreStateMachine::pushState Feb 10 15:08:09 volumio volumio[5075]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:09 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 15:08:09 volumio volumio[5075]: info: CoreCommandRouter::volumioPushState Feb 10 15:08:09 volumio volumio[5075]: info: CoreStateMachine::setRandom null Feb 10 15:08:09 volumio volumio[5075]: info: CoreStateMachine::pushState Feb 10 15:08:09 volumio volumio[5075]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:09 volumio volumio[5075]: info: CoreCommandRouter::volumioPushState Feb 10 15:08:09 volumio volumio[5075]: info: Setting Device type: Raspberry PI Feb 10 15:08:09 volumio volumio[5075]: info: Completed loading Core Plugins Feb 10 15:08:09 volumio volumio[5075]: info: Preparing to generate the ALSA configuration file Feb 10 15:08:09 volumio volumio[5075]: info: VolumeController:: Volume=100 Mute =false Feb 10 15:08:09 volumio volumio[5075]: info: CoreStateMachine::pushState Feb 10 15:08:09 volumio volumio[5075]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:09 volumio volumio[5075]: info: CoreCommandRouter::volumioPushState Feb 10 15:08:09 volumio volumio[5075]: info: Asound.conf file unchanged, so no further update is needed Feb 10 15:08:09 volumio volumio[5075]: info: Output device has changed, restarting MPD Feb 10 15:08:09 volumio sudo[5247]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 15:08:09 volumio sudo[5247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:09 volumio volumio[5075]: info: Output device has changed, restarting Shairport Sync Feb 10 15:08:09 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:09 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 10 15:08:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:09 volumio sudo[5249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 15:08:09 volumio sudo[5249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:09 volumio sudo[5249]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:09 volumio volumio[5075]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 15:08:09 volumio volumio[5075]: info: ___________ START PLUGINS ___________ Feb 10 15:08:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:09 volumio go-librespot[5253]: go-librespot daemon starting... Feb 10 15:08:09 volumio sudo[5252]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 15:08:09 volumio volumio[5075]: info: ControllerMpd::onStart: Initializing MPD Feb 10 15:08:09 volumio volumio[5075]: info: Creating MPD Configuration file Feb 10 15:08:09 volumio sudo[5252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:09 volumio sudo[5247]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:09 volumio go-librespot[5259]: time="2026-02-10T15:08:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:09 volumio go-librespot[5259]: time="2026-02-10T15:08:09+07:00" level=debug msg="app state loaded" Feb 10 15:08:09 volumio go-librespot[5259]: time="2026-02-10T15:08:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:09 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 15:08:09 volumio volumio[5075]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 15:08:09 volumio volumio[5075]: info: [1770710889816] CoreMusicLibrary::Adding element Media Servers Feb 10 15:08:09 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:09 volumio volumio[5075]: info: UPNP Browser: Client initialized successfully Feb 10 15:08:09 volumio sudo[5270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 15:08:09 volumio sudo[5270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:09 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 15:08:09 volumio sudo[5268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 15:08:09 volumio sudo[5268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:09 volumio sudo[5268]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:10 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 15:08:10 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 15:08:10 volumio systemd[1]: mpd.service: Consumed 7.165s CPU time. Feb 10 15:08:10 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 15:08:10 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 15:08:10 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 15:08:10 volumio volumio[5075]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:10 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 15:08:10 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 15:08:10 volumio volumio[5075]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 15:08:10 volumio volumio[5075]: info: [1770710890312] CoreMusicLibrary::Adding element Last_100 Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 15:08:10 volumio volumio[5075]: info: [1770710890331] CoreMusicLibrary::Adding element Webradio Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 15:08:10 volumio volumio[5075]: info: Initializing BBC Radios Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 15:08:10 volumio go-librespot[5259]: time="2026-02-10T15:08:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 15:08:10 volumio go-librespot[5259]: time="2026-02-10T15:08:10+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 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:10 volumio go-librespot[5259]: time="2026-02-10T15:08:10+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 10 15:08:10 volumio volumio[5075]: info: Creating Spotify config file Feb 10 15:08:10 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:10 volumio go-librespot[5259]: time="2026-02-10T15:08:10+07:00" level=info msg="zeroconf server listening on port 33679" Feb 10 15:08:10 volumio sudo[5281]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 15:08:10 volumio sudo[5281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 15:08:10 volumio sudo[5281]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:10 volumio go-librespot[5259]: time="2026-02-10T15:08:10+07:00" level=debug msg="obtained new client token: AACDWgGfZ6ESbLd9vKqGZCik8Sg6awquS/AZ0hx2DpddpkTd0/vESxY4hhZhesK/yiI+Qfc4YmE0Wi4BiYnIullFGKsKg/cTn48h+sUy7R9XKU1Eingbq/EAqfXjDDPn/4dO0QdBSfp9T+tVfVKLCEhi5x0yNwUlkFfK1tusBNBhT6Vao1X5yc0wFPExtkw80GO9ZHlDzym5z7t2yM79UUBmeXoS+PnZZ8oTzLuIY47Q7z5o3CUJMVOH3A==" Feb 10 15:08:11 volumio go-librespot[5259]: time="2026-02-10T15:08:11+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 10 15:08:11 volumio go-librespot[5259]: time="2026-02-10T15:08:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 15:08:11 volumio go-librespot[5259]: time="2026-02-10T15:08:11+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:11 volumio go-librespot[5259]: time="2026-02-10T15:08:11+07:00" level=debug msg="completed challenge" Feb 10 15:08:11 volumio volumio[5195]: Starting albumart workers Feb 10 15:08:11 volumio go-librespot[5259]: time="2026-02-10T15:08: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 10 15:08:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:11 volumio volumio[5196]: Starting albumart workers Feb 10 15:08:11 volumio volumio[5197]: Starting albumart workers Feb 10 15:08:11 volumio volumio[5075]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 15:08:11 volumio volumio[5075]: info: [1770710891817] CoreMusicLibrary::Adding element YouTube Music Feb 10 15:08:11 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:11 volumio volumio[5075]: Cannot find translation for source YouTube Music Feb 10 15:08:11 volumio volumio[5075]: info: Volumio Calling Home Feb 10 15:08:12 volumio sudo[5300]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 15:08:12 volumio sudo[5300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:12 volumio sudo[5300]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:12 volumio volumio[5075]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 15:08:12 volumio volumio[5075]: info: Discovery: Found device Volumio Feb 10 15:08:12 volumio volumio[5075]: info: CoreCommandRouter::volumioGetState Feb 10 15:08:12 volumio volumio[5075]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:12 volumio volumio[5075]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 15:08:12 volumio volumio[5075]: info: Discovery: Found device Volumio Feb 10 15:08:12 volumio volumio[5075]: info: CoreCommandRouter::volumioGetState Feb 10 15:08:12 volumio volumio[5075]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:13 volumio volumio[5075]: info: MPD Permissions set Feb 10 15:08:13 volumio volumio[5075]: info: MPD Permissions set Feb 10 15:08:13 volumio volumio[5075]: info: Upmpdcli Daemon Started Feb 10 15:08:13 volumio volumio[5075]: info: Volumio called home Feb 10 15:08:13 volumio volumio[5075]: info: Spotify config file written Feb 10 15:08:13 volumio sudo[5312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 15:08:13 volumio sudo[5312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:13 volumio volumio[5075]: 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 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio go-librespot[5317]: go-librespot daemon starting... Feb 10 15:08:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio sudo[5312]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:13 volumio go-librespot[5332]: time="2026-02-10T15:08:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:13 volumio go-librespot[5332]: time="2026-02-10T15:08:13+07:00" level=debug msg="app state loaded" Feb 10 15:08:13 volumio go-librespot[5332]: time="2026-02-10T15:08:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:13 volumio volumio[5075]: info: No need to fix Spotify hosts Feb 10 15:08:14 volumio go-librespot[5332]: time="2026-02-10T15:08:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 15:08:14 volumio go-librespot[5332]: time="2026-02-10T15:08:14+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 10 15:08:14 volumio go-librespot[5332]: time="2026-02-10T15:08:14+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 10 15:08:14 volumio go-librespot[5332]: time="2026-02-10T15:08:14+07:00" level=info msg="zeroconf server listening on port 35559" Feb 10 15:08:14 volumio volumio[5075]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 15:08:14 volumio volumio[5075]: SPOTIFY: BQD6IKdESCvVPrBP4c_rvMOyHH5vLFklA0PWmVBMddAjNvTgNTfNlE8muAuitaCZ6Pr0dEnEn0S2hr1sT5oaU9nSiGjnt8iRjJQx1T7GW94kI2AohbIFfFq0BKO6beIhRx6JtTw4eosCqoy5YFQEHiBVQJ-LrDeHvXjqQzuBj4XjOJNuBh2C3iCRBhxENLO6aJjK203RiwGQJo_w_qAiBJTKfZ2jck5yzkY_Zeyo_pT49wDr3w4-Z2RPxTyIVS0HHg0na3QcM-Q2gTjwGD0nWnwJWdFdyK6yF3eE2JIQy8wJ8gLAcBsw4YSv Feb 10 15:08:14 volumio volumio[5075]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 15:08:14 volumio volumio[5075]: info: New Spotify access token = BQD6IKdESCvVPrBP4c_rvMOyHH5vLFklA0PWmVBMddAjNvTgNTfNlE8muAuitaCZ6Pr0dEnEn0S2hr1sT5oaU9nSiGjnt8iRjJQx1T7GW94kI2AohbIFfFq0BKO6beIhRx6JtTw4eosCqoy5YFQEHiBVQJ-LrDeHvXjqQzuBj4XjOJNuBh2C3iCRBhxENLO6aJjK203RiwGQJo_w_qAiBJTKfZ2jck5yzkY_Zeyo_pT49wDr3w4-Z2RPxTyIVS0HHg0na3QcM-Q2gTjwGD0nWnwJWdFdyK6yF3eE2JIQy8wJ8gLAcBsw4YSv Feb 10 15:08:14 volumio volumio[5075]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 15:08:14 volumio go-librespot[5332]: time="2026-02-10T15:08:14+07:00" level=debug msg="obtained new client token: AADEMMaoY63CMgg9nHfXBcxrPvEs6gxJIlBD0RvgReb7ah+mC5fGmPIxBUxCbjkYLC1C3KB4o6u4iYlnVlTOOEfHmWzQMYP9/7fzSg6ouB5iJWVG4fvNHE1C8kUDWAVm7mqmZMe6TEwGOR6oBJ8arpXD5sqZ1urMP7m+5fYe0g81KGHdeQhVVQKD6fi+QKT95mtLcClmjrDXoTTQCLjctHjeIj1xdvoyTsD9ujFO3UuaUbBhnZwuPAO/tw==" Feb 10 15:08:14 volumio volumio[5075]: info: Starting Shairport Sync Feb 10 15:08:14 volumio volumio[5075]: info: Starting Shairport Sync Feb 10 15:08:14 volumio go-librespot[5332]: time="2026-02-10T15:08:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:14 volumio volumio[5075]: info: Starting Shairport Sync Feb 10 15:08:14 volumio sudo[5345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 15:08:14 volumio sudo[5345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:14 volumio go-librespot[5332]: time="2026-02-10T15:08:14+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:14 volumio go-librespot[5332]: time="2026-02-10T15:08:14+07:00" level=debug msg="completed challenge" Feb 10 15:08:14 volumio sudo[5347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 15:08:14 volumio sudo[5347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:14 volumio sudo[5350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 15:08:14 volumio sudo[5350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:14 volumio go-librespot[5332]: time="2026-02-10T15:08:14+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 10 15:08:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 15:08:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 15:08:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 15:08:14 volumio systemd[1]: shairport-sync.service: Consumed 2.229s CPU time. Feb 10 15:08:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 15:08:14 volumio sudo[5345]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 15:08:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 15:08:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 15:08:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 15:08:14 volumio sudo[5350]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:14 volumio sudo[5347]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:15 volumio volumio[5075]: info: Shairport-Sync Started Feb 10 15:08:15 volumio volumio[5075]: Error adding Membership: Error: addMembership EINVAL Feb 10 15:08:15 volumio volumio[5075]: info: Shairport-Sync Started Feb 10 15:08:15 volumio volumio[5075]: info: Shairport-Sync Started Feb 10 15:08:15 volumio volumio[5075]: info: CoreCommandRouter::volumioGetState Feb 10 15:08:15 volumio volumio[5075]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:15 volumio volumio[5075]: 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 10 15:08:15 volumio volumio[5075]: info: Spotify Successfully logged in Feb 10 15:08:15 volumio volumio[5075]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 15:08:15 volumio volumio[5075]: info: [1770710895279] CoreMusicLibrary::Adding element Spotify Feb 10 15:08:15 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:15 volumio volumio[5075]: Cannot find translation for source YouTube Music Feb 10 15:08:15 volumio volumio[5075]: Cannot find translation for source Spotify Feb 10 15:08:16 volumio volumio[5075]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 15:08:16 volumio volumio[5075]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 15:08:16 volumio volumio[5075]: info: VolumeController:: Volume=100 Mute =false Feb 10 15:08:16 volumio volumio[5075]: info: CoreCommandRouter::volumioGetState Feb 10 15:08:16 volumio volumio[5075]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:16 volumio volumio[5075]: info: CoreStateMachine::pushState Feb 10 15:08:16 volumio volumio[5075]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:16 volumio volumio[5075]: info: CoreCommandRouter::volumioPushState Feb 10 15:08:17 volumio volumio[5075]: info: go-librespot daemon successfully initialized Feb 10 15:08:17 volumio mpd[5298]: 2026-02-10T15:08:17 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 15:08:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 10 15:08:17 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 15:08:17 volumio sudo[5270]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:17 volumio sudo[5252]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:17 volumio go-librespot[5389]: go-librespot daemon starting... Feb 10 15:08:17 volumio go-librespot[5391]: time="2026-02-10T15:08:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:17 volumio go-librespot[5391]: time="2026-02-10T15:08:17+07:00" level=debug msg="app state loaded" Feb 10 15:08:17 volumio go-librespot[5391]: time="2026-02-10T15:08:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:18 volumio volumio[5075]: error: MPD error: The expression evaluated to a falsy value: Feb 10 15:08:18 volumio volumio[5075]: assert.ok(self.idling) Feb 10 15:08:18 volumio volumio[5075]: error: The expression evaluated to a falsy value: Feb 10 15:08:18 volumio volumio[5075]: assert.ok(self.idling) Feb 10 15:08:18 volumio volumio[5075]: info: MPD running with PID5298 Feb 10 15:08:18 volumio volumio[5075]: ,establishing connection Feb 10 15:08:18 volumio volumio[5075]: error: updateQueue error: null Feb 10 15:08:18 volumio volumio[5075]: info: Completed starting Core Plugins Feb 10 15:08:18 volumio volumio[5075]: info: ------------------------------------------- Feb 10 15:08:18 volumio volumio[5075]: info: ----- MyVolumio plugins startup ---- Feb 10 15:08:18 volumio volumio[5075]: info: ------------------------------------------- Feb 10 15:08:18 volumio volumio[5075]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 15:08:18 volumio volumio[5075]: error: updateQueue error: null Feb 10 15:08:18 volumio go-librespot[5391]: time="2026-02-10T15:08:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 15:08:18 volumio go-librespot[5391]: time="2026-02-10T15:08:18+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 10 15:08:18 volumio go-librespot[5391]: time="2026-02-10T15:08:18+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 10 15:08:18 volumio go-librespot[5391]: time="2026-02-10T15:08:18+07:00" level=info msg="zeroconf server listening on port 33111" Feb 10 15:08:18 volumio go-librespot[5391]: time="2026-02-10T15:08:18+07:00" level=debug msg="obtained new client token: AAAoGtV3dJzoxr1dZGJ1kdQYDzaWz6idRVP7vw5BAfRqB2AIBwS5kR69xPNgPjg5ydf4XCfeF9x1WePgtBE9B2e6l90UocFC0fm4gUvXxTvoNX8JWkWxvmCvGuMQJx3rJbmlUSeNZOJIyzlMiz39Gi6DpHwoo2DaJC4mB3FYJn2HGQAL2YVy9flYLPVOh97O7BSKl66ZsRevgL47EgrVztUYfRjfwd/wUVxhsvOSWlQmAnPfq/73T/yxrA==" Feb 10 15:08:18 volumio go-librespot[5391]: time="2026-02-10T15:08:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:18 volumio go-librespot[5391]: time="2026-02-10T15:08:18+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:18 volumio go-librespot[5391]: time="2026-02-10T15:08:18+07:00" level=debug msg="completed challenge" Feb 10 15:08:18 volumio go-librespot[5391]: time="2026-02-10T15:08:18+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 10 15:08:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:20 volumio volumio[5075]: info: Initializing connection to go-librespot Websocket Feb 10 15:08:20 volumio volumio[5075]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 15:08:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 10 15:08:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:22 volumio go-librespot[5398]: go-librespot daemon starting... Feb 10 15:08:22 volumio go-librespot[5399]: time="2026-02-10T15:08:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:22 volumio go-librespot[5399]: time="2026-02-10T15:08:22+07:00" level=debug msg="app state loaded" Feb 10 15:08:22 volumio go-librespot[5399]: time="2026-02-10T15:08:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:22 volumio go-librespot[5399]: time="2026-02-10T15:08:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 15:08:22 volumio go-librespot[5399]: time="2026-02-10T15:08:22+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 10 15:08:22 volumio go-librespot[5399]: time="2026-02-10T15:08:22+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 10 15:08:22 volumio go-librespot[5399]: time="2026-02-10T15:08:22+07:00" level=info msg="zeroconf server listening on port 33463" Feb 10 15:08:22 volumio volumio[5075]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 15:08:22 volumio go-librespot[5399]: time="2026-02-10T15:08:22+07:00" level=debug msg="obtained new client token: AAAwZ3EepuYgqTx6Eoj8+y6AdTeypDygNWNiqKMQVcOMyXOT9HXpeVUYTCigRduBDxvfLkDcyrRMqsmmMJIGDn8DXeJPeHXWuNk5i0Z9xJx5iLA1v33IeE2gITwoBioXw16nR5sJvIryEheUNWxG/AdNEXwId3LT8lOupkC1p4gwvBpGHHE3tobDyss/5MqDyp1pjPT758l0ZT+8CfnNt/PMMaL6icttyDJc81wnJzIv68hrjhz29GTQCw==" Feb 10 15:08:22 volumio go-librespot[5399]: time="2026-02-10T15:08:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:23 volumio go-librespot[5399]: time="2026-02-10T15:08:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 15:08:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:23 volumio volumio[5075]: info: Initializing connection to go-librespot Websocket Feb 10 15:08:23 volumio volumio[5075]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 15:08:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 10 15:08:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:26 volumio volumio[5075]: info: Initializing connection to go-librespot Websocket Feb 10 15:08:26 volumio volumio[5075]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 15:08:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:26 volumio go-librespot[5406]: go-librespot daemon starting... Feb 10 15:08:26 volumio go-librespot[5407]: time="2026-02-10T15:08:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:26 volumio go-librespot[5407]: time="2026-02-10T15:08:26+07:00" level=debug msg="app state loaded" Feb 10 15:08:26 volumio go-librespot[5407]: time="2026-02-10T15:08:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:26 volumio go-librespot[5407]: time="2026-02-10T15:08:26+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 10 15:08:26 volumio go-librespot[5407]: time="2026-02-10T15:08:26+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 10 15:08:26 volumio go-librespot[5407]: time="2026-02-10T15:08:26+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 10 15:08:26 volumio go-librespot[5407]: time="2026-02-10T15:08:26+07:00" level=info msg="zeroconf server listening on port 43563" Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 15:08:26 volumio volumio[5075]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 15:08:26 volumio volumio[5075]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 15:08:26 volumio volumio[5075]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 15:08:26 volumio volumio[5075]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 15:08:26 volumio volumio[5075]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 15:08:26 volumio volumio[5075]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 15:08:26 volumio volumio[5075]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 15:08:26 volumio volumio[5075]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 15:08:27 volumio volumio[5075]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 15:08:27 volumio go-librespot[5407]: time="2026-02-10T15:08:27+07:00" level=debug msg="obtained new client token: AACEoohsfx15aJVbnglDF6om2KM/YgTribAOA6YpDASJks7GwlgLqXZqUUuAbQaUnXaZDmp3MBLPFTirHKKSlbmdP/FhEEhwltBgQj/Tm7Uwj4RiN+1ng4Wy4IgD8zbb9mLNbi1HHT9qTJ6E8wLtltuE3g76QNAWbQ1hYRgJ5dLO2XqTDDNtazOJKvTpL6FEtdzkZk6zd2dxuhHkQH9d07xtvx8j7KfOa4lTOVOo/3knl0QBm502eNk=" Feb 10 15:08:27 volumio go-librespot[5407]: time="2026-02-10T15:08:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:27 volumio go-librespot[5407]: time="2026-02-10T15:08:27+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:27 volumio go-librespot[5407]: time="2026-02-10T15:08:27+07:00" level=debug msg="completed challenge" Feb 10 15:08:27 volumio go-librespot[5407]: time="2026-02-10T15:08:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 15:08:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:28 volumio volumio[5075]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 15:08:28 volumio volumio[5075]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 15:08:28 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:28 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:28 volumio volumio[5075]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 15:08:28 volumio volumio[5075]: info: MyVolumio login type: Token Feb 10 15:08:28 volumio volumio[5075]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 15:08:28 volumio volumio[5075]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 15:08:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 10 15:08:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:30 volumio volumio[5075]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 15:08:30 volumio volumio[5075]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 15:08:30 volumio volumio[5075]: info: Streaming services startup Feb 10 15:08:30 volumio volumio[5075]: info: Starting Streaming Daemon Feb 10 15:08:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:30 volumio go-librespot[5430]: go-librespot daemon starting... Feb 10 15:08:30 volumio sudo[5432]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 15:08:30 volumio volumio[5075]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 15:08:30 volumio sudo[5432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:30 volumio go-librespot[5433]: time="2026-02-10T15:08:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:30 volumio go-librespot[5433]: time="2026-02-10T15:08:30+07:00" level=debug msg="app state loaded" Feb 10 15:08:30 volumio go-librespot[5433]: time="2026-02-10T15:08:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:30 volumio sudo[5432]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:30 volumio volumio[5075]: info: Initializing connection to go-librespot Websocket Feb 10 15:08:30 volumio volumio[5075]: error: Cannot start Volumio Streaming Daemon Feb 10 15:08:30 volumio volumio[5075]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 15:08:30 volumio volumio[5075]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 15:08:30 volumio go-librespot[5433]: time="2026-02-10T15:08:30+07:00" level=debug msg="new websocket client" Feb 10 15:08:30 volumio volumio[5075]: info: Connection to go-librespot Websocket established Feb 10 15:08:31 volumio go-librespot[5433]: time="2026-02-10T15:08:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 15:08:31 volumio go-librespot[5433]: time="2026-02-10T15:08:31+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 10 15:08:31 volumio go-librespot[5433]: time="2026-02-10T15:08:31+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 10 15:08:31 volumio go-librespot[5433]: time="2026-02-10T15:08:31+07:00" level=info msg="zeroconf server listening on port 36153" Feb 10 15:08:31 volumio go-librespot[5433]: time="2026-02-10T15:08:31+07:00" level=debug msg="obtained new client token: AAAXOUSNZGFASiDdSFfcNyPg3PUwXoprDA8MjLidLERJdH+F+VGacj2INxbmIJmXkekrVmSgliK5RwH0TXslZOBK8Agr/4atjTr9EqgrCyLHyGBAKDE6ojuAjmzx3SsYhF9oQHbwYUts/ezTOEzX8ZTx1mPYMWp7kzYdfpJfNgwuCmTff+V05hgN9lkfP1Y9w8Y+pbVFT1596E7Q1Ly6s+cqUN2AOs6MOYyoO63u4mlZpB5VBylxDHc3Dw==" Feb 10 15:08:31 volumio go-librespot[5433]: time="2026-02-10T15:08:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:31 volumio go-librespot[5433]: time="2026-02-10T15:08:31+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:31 volumio go-librespot[5433]: time="2026-02-10T15:08:31+07:00" level=debug msg="completed challenge" Feb 10 15:08:31 volumio go-librespot[5433]: time="2026-02-10T15:08: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 10 15:08:31 volumio volumio[5075]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 10 15:08:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:31 volumio volumio[5075]: info: Connection to go-librespot Websocket closed Feb 10 15:08:32 volumio volumio[5075]: info: MyVolumio token set successfully Feb 10 15:08:32 volumio volumio[5075]: info: MYVOLUMIO: Adding device Feb 10 15:08:32 volumio volumio[5075]: info: MYVOLUMIO: Evaluating Server Feb 10 15:08:33 volumio volumio[5075]: info: MyVolumio status changed Feb 10 15:08:33 volumio volumio[5075]: info: Streaming services startup Feb 10 15:08:33 volumio volumio[5075]: info: Starting Streaming Daemon Feb 10 15:08:33 volumio volumio[5075]: info: Removing browser output: myVolumio user plan is not superstar Feb 10 15:08:33 volumio volumio[5075]: info: Removing audio output: Feb 10 15:08:33 volumio volumio[5075]: info: Stoppping Tunnel 1 Feb 10 15:08:33 volumio sudo[5470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 15:08:33 volumio sudo[5470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:33 volumio sudo[5470]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:33 volumio volumio[5075]: error: Cannot start Volumio Streaming Daemon Feb 10 15:08:33 volumio volumio[5075]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 15:08:33 volumio volumio[5075]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 15:08:33 volumio sudo[5473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 10 15:08:33 volumio sudo[5473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:33 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 10 15:08:33 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 10 15:08:33 volumio volumio[5075]: info: Setting Geolocation for MyVolumio to as1 Feb 10 15:08:33 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:33 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:33 volumio volumio[5075]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:33 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 10 15:08:33 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 10 15:08:33 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 10 15:08:33 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 10 15:08:33 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 10 15:08:33 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 10 15:08:33 volumio sudo[5473]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:33 volumio volumio[5075]: info: Remote SSH Stopped Feb 10 15:08:33 volumio volumio[5075]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 10 15:08:33 volumio volumio[5075]: info: Getting Spotify volume Feb 10 15:08:33 volumio volumio[5075]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 15:08:33 volumio volumio[5075]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 15:08:33 volumio volumio[5075]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 15:08:33 volumio volumio[5075]: errno: -111, Feb 10 15:08:33 volumio volumio[5075]: code: 'ECONNREFUSED', Feb 10 15:08:33 volumio volumio[5075]: syscall: 'connect', Feb 10 15:08:33 volumio volumio[5075]: address: '127.0.0.1', Feb 10 15:08:33 volumio volumio[5075]: port: 9879, Feb 10 15:08:33 volumio volumio[5075]: response: undefined Feb 10 15:08:33 volumio volumio[5075]: } Feb 10 15:08:33 volumio volumio[5075]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 15:08:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 10 15:08:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:34 volumio go-librespot[5488]: go-librespot daemon starting... Feb 10 15:08:34 volumio go-librespot[5489]: time="2026-02-10T15:08:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:34 volumio go-librespot[5489]: time="2026-02-10T15:08:34+07:00" level=debug msg="app state loaded" Feb 10 15:08:34 volumio go-librespot[5489]: time="2026-02-10T15:08:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:35 volumio sudo[5498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 15:07' Feb 10 15:08:35 volumio sudo[5498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:35 volumio go-librespot[5489]: time="2026-02-10T15:08: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 10 15:08:35 volumio go-librespot[5489]: time="2026-02-10T15:08: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 10 15:08:35 volumio go-librespot[5489]: time="2026-02-10T15:08: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 10 15:08:35 volumio go-librespot[5489]: time="2026-02-10T15:08:35+07:00" level=info msg="zeroconf server listening on port 39995" Feb 10 15:08:35 volumio go-librespot[5489]: time="2026-02-10T15:08:35+07:00" level=debug msg="obtained new client token: AACoAII6n68QJIjvONNkcJ0NmU8neIeOJT/e5gBp8cZ+bMg2O52m/k9+qkTXsDmRJO1BZxr9ieo3oeIS5eTCIfr0ZZyjtYCETpydr8ZGrELAL+2avutyLTrueCLhkoECPEQyrry9PCGd3kDnde9268Sd+YoPpM8q4FRge4YcJIeypsZe7jnJl/voBQBmDSCMQeyMGMgOlAVE/orwUnz1tl4CiBup+aA3wgQsjuZu41uBhO8qqgEb6lCadg==" Feb 10 15:08:35 volumio sudo[5498]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:35 volumio go-librespot[5489]: time="2026-02-10T15:08:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:35 volumio go-librespot[5489]: time="2026-02-10T15:08:35+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:35 volumio go-librespot[5489]: time="2026-02-10T15:08:35+07:00" level=debug msg="completed challenge" Feb 10 15:08:35 volumio volumio-remote-updater[643]: [2026-02-10 15:08:35] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 10 15:08:35 volumio volumio-remote-updater[643]: [2026-02-10 15:08:35] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 10 15:08:35 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:35 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 15:08:35 volumio systemd[1]: volumio.service: Consumed 56.900s CPU time. Feb 10 15:08:35 volumio go-librespot[5489]: time="2026-02-10T15:08:35+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 10 15:08:36 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 15:08:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:36 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10389. Feb 10 15:08:36 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 15:08:36 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 15:08:36 volumio systemd[1]: volumio.service: Consumed 56.900s CPU time. Feb 10 15:08:36 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 15:08:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 10 15:08:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:39 volumio go-librespot[5520]: go-librespot daemon starting... Feb 10 15:08:39 volumio go-librespot[5521]: time="2026-02-10T15:08:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:39 volumio go-librespot[5521]: time="2026-02-10T15:08:39+07:00" level=debug msg="app state loaded" Feb 10 15:08:39 volumio go-librespot[5521]: time="2026-02-10T15:08:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:39 volumio volumio[5510]: info: ------------------------------------------- Feb 10 15:08:39 volumio volumio[5510]: info: ----- Volumio3 ---- Feb 10 15:08:39 volumio volumio[5510]: info: ------------------------------------------- Feb 10 15:08:39 volumio volumio[5510]: info: ----- System startup ---- Feb 10 15:08:39 volumio volumio[5510]: info: ------------------------------------------- Feb 10 15:08:39 volumio go-librespot[5521]: time="2026-02-10T15:08:39+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 10 15:08:39 volumio go-librespot[5521]: time="2026-02-10T15:08:39+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 10 15:08:39 volumio go-librespot[5521]: time="2026-02-10T15:08:39+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 10 15:08:39 volumio go-librespot[5521]: time="2026-02-10T15:08:39+07:00" level=info msg="zeroconf server listening on port 35167" Feb 10 15:08:40 volumio go-librespot[5521]: time="2026-02-10T15:08:40+07:00" level=debug msg="obtained new client token: AAAUPTx/ZoYzts7yQiwnTXuRFnWzPX1y/wKNSLfexvBGsoBk0qV3LvI2ruIYtTO6vfxy6GiZie6gyESxRonZbDOl2S8vpC9ltACgLN+kOalcWxskZLki+5eSj56Wf/jaLzJvyZIb11bjg32suEdD6GlIzAJvNy3GQXu4M01a58acQNitETpWXcy+CRl9JcYdiJ0GvdYDYKrKXTm9IDy8pfexWByHTqlCmpRJwnqoV1DROW7ETzZo/xC6Jw==" Feb 10 15:08:40 volumio go-librespot[5521]: time="2026-02-10T15:08:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:40 volumio go-librespot[5521]: time="2026-02-10T15:08:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 15:08:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:40 volumio volumio-remote-updater[643]: [2026-02-10 15:08:40] [connect] Successful connection Feb 10 15:08:41 volumio volumio[5510]: info: MYVOLUMIO Environment detected Feb 10 15:08:41 volumio volumio[5510]: info: Plugin folders cleanup Feb 10 15:08:41 volumio volumio[5510]: info: Scanning into folder /volumio/app/plugins/ Feb 10 15:08:41 volumio volumio[5510]: info: Scanning category audio_interface Feb 10 15:08:41 volumio volumio[5510]: info: Scanning category miscellanea Feb 10 15:08:41 volumio volumio[5510]: info: Scanning category music_service Feb 10 15:08:41 volumio volumio[5510]: info: Scanning category plugins.json Feb 10 15:08:41 volumio volumio[5510]: info: Scanning category system_controller Feb 10 15:08:41 volumio volumio[5510]: info: Scanning category user_interface Feb 10 15:08:41 volumio volumio[5510]: info: Scanning into folder /data/plugins/ Feb 10 15:08:41 volumio volumio[5510]: info: Scanning category music_service Feb 10 15:08:41 volumio volumio[5510]: info: Plugin folders cleanup completed Feb 10 15:08:41 volumio volumio[5510]: info: ------------------------------------------- Feb 10 15:08:41 volumio volumio[5510]: info: ----- Core plugins startup ---- Feb 10 15:08:41 volumio volumio[5510]: info: ------------------------------------------- Feb 10 15:08:41 volumio volumio[5510]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 15:08:41 volumio volumio[5510]: info: Adding plugin upnp to MyMusic Plugins Feb 10 15:08:41 volumio volumio[5510]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 15:08:41 volumio volumio[5510]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 15:08:41 volumio volumio[5510]: info: Loading plugins from folder /data/plugins/ Feb 10 15:08:41 volumio volumio[5510]: info: Loading plugin "system"... Feb 10 15:08:41 volumio volumio[5510]: info: Loading plugin "appearance"... Feb 10 15:08:43 volumio volumio[5510]: info: Loading plugin "network"... Feb 10 15:08:43 volumio volumio[5510]: info: Refreshing Cached IP Addresses Feb 10 15:08:43 volumio sudo[5541]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 15:08:43 volumio sudo[5541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:43 volumio volumio[5510]: info: Loading plugin "services"... Feb 10 15:08:43 volumio sudo[5543]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 15:08:43 volumio sudo[5543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:43 volumio sudo[5541]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:43 volumio volumio[5510]: info: Loading plugin "alsa_controller"... Feb 10 15:08:43 volumio sudo[5543]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:43 volumio sudo[5551]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 15:08:43 volumio sudo[5551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 10 15:08:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:43 volumio go-librespot[5571]: go-librespot daemon starting... Feb 10 15:08:43 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 15:08:43 volumio volumio[5510]: info: Loading plugin "wizard"... Feb 10 15:08:43 volumio volumio[5510]: info: Loading plugin "networkfs"... Feb 10 15:08:43 volumio go-librespot[5576]: time="2026-02-10T15:08:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:43 volumio go-librespot[5576]: time="2026-02-10T15:08:43+07:00" level=debug msg="app state loaded" Feb 10 15:08:43 volumio go-librespot[5576]: time="2026-02-10T15:08:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:43 volumio volumio[5510]: info: Starting Udev Watcher for removable devices Feb 10 15:08:43 volumio volumio[5510]: info: Ignoring mount for partition: boot Feb 10 15:08:43 volumio volumio[5510]: info: Ignoring mount for partition: volumio Feb 10 15:08:43 volumio volumio[5510]: info: Ignoring mount for partition: volumio_data Feb 10 15:08:43 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 15:08:43 volumio volumio[5510]: info: Loading plugin "volumio_command_line_client"... Feb 10 15:08:43 volumio volumio[5510]: info: Loading plugin "upnp"... Feb 10 15:08:43 volumio volumio[5510]: info: [1770710923580] Starting Upmpd Daemon Feb 10 15:08:43 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 15:08:43 volumio volumio[5510]: info: Loading plugin "my_music"... Feb 10 15:08:43 volumio volumio[5510]: info: Loading plugin "mpd"... Feb 10 15:08:43 volumio go-librespot[5576]: time="2026-02-10T15:08:43+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 10 15:08:43 volumio go-librespot[5576]: time="2026-02-10T15:08:43+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 10 15:08:43 volumio go-librespot[5576]: time="2026-02-10T15:08:43+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 10 15:08:44 volumio go-librespot[5576]: time="2026-02-10T15:08:44+07:00" level=info msg="zeroconf server listening on port 35621" Feb 10 15:08:44 volumio go-librespot[5576]: time="2026-02-10T15:08:44+07:00" level=debug msg="obtained new client token: AACR24U8JY30hqaPERyiaOdUVBjcBbmbFDqZUN8t317SnDM+epqOhbMANC8dV6s4dTG+60ys3LqF5r2rgdXW5aHKSNE7zDswlIh11Bv8rWSDzf2FxHmSt3ffGf7I8ibOrlR41BNmcFRnYTwQEQ2j5X+zAcNXmTnh7HuUYxg3jpNpQ4lfZNKLNAhlIQ6QxLyp2b9YAfRDf8FdFJlU2FORB8YoWHkc79sM6ZMVbLwfoW1fSGAP+iCdSuw=" Feb 10 15:08:44 volumio volumio[5510]: info: Loading plugin "upnp_browser"... Feb 10 15:08:44 volumio go-librespot[5576]: time="2026-02-10T15:08:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:44 volumio go-librespot[5576]: time="2026-02-10T15:08:44+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:44 volumio go-librespot[5576]: time="2026-02-10T15:08:44+07:00" level=debug msg="completed challenge" Feb 10 15:08:44 volumio go-librespot[5576]: time="2026-02-10T15:08: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 10 15:08:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:46 volumio sudo[5551]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:47 volumio volumio[5510]: info: Starting UPNP Browser Feb 10 15:08:47 volumio volumio[5510]: info: Loading plugin "alarm-clock"... Feb 10 15:08:47 volumio volumio[5510]: info: Loading plugin "airplay_emulation"... Feb 10 15:08:47 volumio volumio[5510]: info: Starting Shairport Sync Feb 10 15:08:47 volumio volumio[5510]: info: Loading plugin "last_100"... Feb 10 15:08:47 volumio volumio[5510]: info: Loading plugin "webradio"... Feb 10 15:08:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 10 15:08:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:47 volumio go-librespot[5583]: go-librespot daemon starting... Feb 10 15:08:47 volumio go-librespot[5584]: time="2026-02-10T15:08:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:47 volumio go-librespot[5584]: time="2026-02-10T15:08:47+07:00" level=debug msg="app state loaded" Feb 10 15:08:47 volumio go-librespot[5584]: time="2026-02-10T15:08:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:47 volumio volumio[5510]: info: Loading plugin "i2s_dacs"... Feb 10 15:08:47 volumio volumio[5510]: info: Loading plugin "volumiodiscovery"... Feb 10 15:08:47 volumio volumio[5510]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 15:08:47 volumio volumio[5510]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 15:08:47 volumio volumio[5510]: *** WARNING *** For more information see Feb 10 15:08:47 volumio volumio[5510]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 15:08:47 volumio volumio[5510]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 15:08:47 volumio volumio[5510]: *** WARNING *** For more information see Feb 10 15:08:47 volumio node[5510]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 15:08:47 volumio node[5510]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 15:08:47 volumio node[5510]: *** WARNING *** For more information see Feb 10 15:08:47 volumio node[5510]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 15:08:47 volumio node[5510]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 15:08:47 volumio node[5510]: *** WARNING *** For more information see Feb 10 15:08:47 volumio volumio[5510]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 15:08:47 volumio volumio[5510]: info: Discovery: Started advertising with name: Volumio Feb 10 15:08:47 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 15:08:47 volumio volumio[5510]: info: Loading plugin "spop"... Feb 10 15:08:48 volumio go-librespot[5584]: time="2026-02-10T15:08: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 15:08:48 volumio go-librespot[5584]: time="2026-02-10T15:08:48+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 10 15:08:48 volumio go-librespot[5584]: time="2026-02-10T15:08:48+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 10 15:08:48 volumio go-librespot[5584]: time="2026-02-10T15:08:48+07:00" level=info msg="zeroconf server listening on port 36119" Feb 10 15:08:48 volumio go-librespot[5584]: time="2026-02-10T15:08:48+07:00" level=debug msg="obtained new client token: AABlLO8rCMPXFoSiB81UELgYRgGEDP++u0S/GRr71UkOU02TqN8PJLhaM5geDYxrEYZiN5sFrtLvN5OFk8ZFlnKuGLVEpTMYLYU6qJTXXyLnbFH4gjWj6NHvGV86lKB2Tkmv/ize7mRpbrGBRngPr0eSBoN+ZTlE3AykyojRn6ffAox3Sv1a1dE57DVe8KczyAQ+7UjTUo8dBy3qwfCn8pZYJU/3cmzvsUNVmKqMIrhOrweO4Xz+LpriKw==" Feb 10 15:08:48 volumio go-librespot[5584]: time="2026-02-10T15:08:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:48 volumio go-librespot[5584]: time="2026-02-10T15:08:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 15:08:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:49 volumio volumio[5510]: info: Loading plugin "ytcr"... Feb 10 15:08:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 10 15:08:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:51 volumio go-librespot[5594]: go-librespot daemon starting... Feb 10 15:08:51 volumio go-librespot[5595]: time="2026-02-10T15:08:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:51 volumio go-librespot[5595]: time="2026-02-10T15:08:51+07:00" level=debug msg="app state loaded" Feb 10 15:08:51 volumio go-librespot[5595]: time="2026-02-10T15:08:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:52 volumio volumio[5510]: info: Loading plugin "ytmusic"... Feb 10 15:08:52 volumio go-librespot[5595]: time="2026-02-10T15:08: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-gew1.spotify.com:80]" Feb 10 15:08:52 volumio go-librespot[5595]: time="2026-02-10T15:08:52+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 10 15:08:52 volumio go-librespot[5595]: time="2026-02-10T15:08:52+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 10 15:08:52 volumio go-librespot[5595]: time="2026-02-10T15:08:52+07:00" level=info msg="zeroconf server listening on port 45025" Feb 10 15:08:52 volumio go-librespot[5595]: time="2026-02-10T15:08:52+07:00" level=debug msg="obtained new client token: AAA5OLUCSOJpsJ77rU/4LJQ/x/N/fXDBKs1RJB4LAeyLTbMlixSLJyM+n06el+yZfvKSdQgDkrokKWCk/fxIyCE0eS76if7X/vjisw74hcJPta1yfboDY0CVXjnIBRz9C35t6jr6rPTsOWCiEhcUdCDJRRvJ000iSyEiOv1ttBIR3X3m/oSPAWW/6XNeYbScZrOflmovoRqxX8GoOXrQKiBgDzXi9Nv65w8wMnkL+AtPPzkucnQ5dCjSPg==" Feb 10 15:08:52 volumio go-librespot[5595]: time="2026-02-10T15:08:52+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 10 15:08:52 volumio go-librespot[5595]: time="2026-02-10T15:08:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 15:08:53 volumio go-librespot[5595]: time="2026-02-10T15:08:53+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:53 volumio go-librespot[5595]: time="2026-02-10T15:08:53+07:00" level=debug msg="completed challenge" Feb 10 15:08:53 volumio go-librespot[5595]: time="2026-02-10T15:08: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 10 15:08:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:53 volumio volumio-remote-updater[643]: [2026-02-10 15:08:53] [connect] Successful connection Feb 10 15:08:53 volumio volumio[5510]: info: Loading plugin "outputs"... Feb 10 15:08:53 volumio volumio[5510]: info: Loading plugin "albumart"... Feb 10 15:08:53 volumio volumio[5510]: info: Plugin example_plugin is not enabled Feb 10 15:08:53 volumio volumio[5510]: info: Loading plugin "inputs"... Feb 10 15:08:53 volumio volumio[5510]: info: Loading plugin "updater_comm"... Feb 10 15:08:53 volumio volumio[5510]: info: Plugin mpdemulation is not enabled Feb 10 15:08:53 volumio volumio[5510]: info: Loading plugin "rest_api"... Feb 10 15:08:53 volumio volumio[5510]: info: Loading plugin "websocket"... Feb 10 15:08:53 volumio volumio[5510]: info: Starting Socket.io Server version 1.7.4 Feb 10 15:08:53 volumio volumio[5510]: info: Loading plugin "RoonBridge"... Feb 10 15:08:54 volumio volumio[5510]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 15:08:54 volumio volumio[5510]: info: Loading i18n strings for locale en Feb 10 15:08:54 volumio volumio[5510]: Updating browse sources language Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:54 volumio volumio[5616]: Forking 3 albumart workers Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::initPlayerControls Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 15:08:54 volumio volumio[5510]: Express server listening on port 3000 Feb 10 15:08:54 volumio volumio[5510]: [Metrics] WebUI: 15s 994.19ms Feb 10 15:08:54 volumio volumio[5510]: info: CoreStateMachine::resetVolumioState Feb 10 15:08:54 volumio volumio[5510]: info: CoreStateMachine::getcurrentVolume Feb 10 15:08:54 volumio volumio[5510]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 15:08:54 volumio sudo[5658]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 15:08:54 volumio sudo[5658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:54 volumio sudo[5658]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:54 volumio sudo[5660]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 15:08:54 volumio sudo[5660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:54 volumio sudo[5660]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:54 volumio volumio[5510]: info: Volumio Network Manager: Network status updated: 1 Feb 10 15:08:55 volumio volumio-remote-updater[643]: [2026-02-10 15:08:55] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770710933 101 Feb 10 15:08:55 volumio volumio[5510]: 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 10 15:08:55 volumio volumio[5510]: info: VolumeController:: Volume=100 Mute =false Feb 10 15:08:55 volumio volumio[5510]: info: CoreStateMachine::pushState Feb 10 15:08:55 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:55 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 15:08:55 volumio volumio[5510]: info: CoreCommandRouter::volumioPushState Feb 10 15:08:55 volumio volumio[5510]: info: CoreStateMachine::updateTrackBlock Feb 10 15:08:55 volumio volumio[5510]: info: CorePlayQueue::getTrackBlock Feb 10 15:08:55 volumio volumio[5510]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 15:08:55 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:55 volumio volumio[5510]: info: Reloading queue from file Feb 10 15:08:55 volumio volumio[5510]: info: CoreStateMachine::setRepeat null single undefined Feb 10 15:08:55 volumio volumio[5510]: info: CoreStateMachine::pushState Feb 10 15:08:55 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:55 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 15:08:55 volumio volumio[5510]: info: CoreCommandRouter::volumioPushState Feb 10 15:08:55 volumio volumio[5510]: info: CoreStateMachine::setRandom null Feb 10 15:08:55 volumio volumio[5510]: info: CoreStateMachine::pushState Feb 10 15:08:55 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:55 volumio volumio[5510]: info: CoreCommandRouter::volumioPushState Feb 10 15:08:55 volumio volumio[5510]: info: Setting Device type: Raspberry PI Feb 10 15:08:55 volumio volumio[5510]: info: Completed loading Core Plugins Feb 10 15:08:55 volumio volumio[5510]: info: Preparing to generate the ALSA configuration file Feb 10 15:08:55 volumio volumio[5510]: info: VolumeController:: Volume=100 Mute =false Feb 10 15:08:55 volumio volumio[5510]: info: CoreStateMachine::pushState Feb 10 15:08:55 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:55 volumio volumio[5510]: info: CoreCommandRouter::volumioPushState Feb 10 15:08:55 volumio volumio[5510]: info: Asound.conf file unchanged, so no further update is needed Feb 10 15:08:55 volumio volumio[5510]: info: Output device has changed, restarting MPD Feb 10 15:08:55 volumio sudo[5678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 15:08:55 volumio sudo[5678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:55 volumio volumio[5510]: info: Output device has changed, restarting Shairport Sync Feb 10 15:08:55 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:55 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:55 volumio sudo[5680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 15:08:55 volumio sudo[5680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:55 volumio sudo[5683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 15:08:55 volumio sudo[5683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:55 volumio sudo[5680]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:56 volumio sudo[5678]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:56 volumio volumio[5510]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 15:08:56 volumio volumio[5510]: info: ___________ START PLUGINS ___________ Feb 10 15:08:56 volumio volumio[5510]: info: ControllerMpd::onStart: Initializing MPD Feb 10 15:08:56 volumio volumio[5510]: info: Creating MPD Configuration file Feb 10 15:08:56 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 15:08:56 volumio volumio[5510]: info: [1770710936136] CoreMusicLibrary::Adding element Media Servers Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:56 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 15:08:56 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 15:08:56 volumio systemd[1]: mpd.service: Consumed 7.074s CPU time. Feb 10 15:08:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 10 15:08:56 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 15:08:56 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 15:08:56 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 15:08:56 volumio volumio[5510]: info: UPNP Browser: Client initialized successfully Feb 10 15:08:56 volumio sudo[5693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 15:08:56 volumio sudo[5693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:56 volumio sudo[5691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:56 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 15:08:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:56 volumio sudo[5691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:56 volumio sudo[5691]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:56 volumio go-librespot[5699]: go-librespot daemon starting... Feb 10 15:08:56 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 15:08:56 volumio go-librespot[5701]: time="2026-02-10T15:08:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:56 volumio go-librespot[5701]: time="2026-02-10T15:08:56+07:00" level=debug msg="app state loaded" Feb 10 15:08:56 volumio go-librespot[5701]: time="2026-02-10T15:08:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:08:56 volumio volumio[5510]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:56 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 15:08:56 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 15:08:56 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 15:08:56 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 15:08:56 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 15:08:56 volumio volumio[5510]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 15:08:56 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 15:08:56 volumio volumio[5510]: info: [1770710936579] CoreMusicLibrary::Adding element Last_100 Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:56 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 15:08:56 volumio volumio[5510]: info: [1770710936616] CoreMusicLibrary::Adding element Webradio Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 15:08:56 volumio volumio[5510]: info: Initializing BBC Radios Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 15:08:56 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:57 volumio volumio[5510]: info: Creating Spotify config file Feb 10 15:08:57 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:57 volumio sudo[5714]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 15:08:57 volumio sudo[5714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 15:08:57 volumio go-librespot[5701]: time="2026-02-10T15:08:57+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 10 15:08:57 volumio go-librespot[5701]: time="2026-02-10T15:08:57+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 10 15:08:57 volumio go-librespot[5701]: time="2026-02-10T15:08:57+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 10 15:08:57 volumio sudo[5714]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:57 volumio go-librespot[5701]: time="2026-02-10T15:08:57+07:00" level=info msg="zeroconf server listening on port 40731" Feb 10 15:08:57 volumio go-librespot[5701]: time="2026-02-10T15:08:57+07:00" level=debug msg="obtained new client token: AAD6UhK0NmObzA997ViZdStwSBgDoy+grs6vAaT6YNHMXUZIDLlZ40B+pzASHqWHe5gn4RfZxadpw8GBTj6BzU/tQOp1ZcvFY+790luSKf4v02DEOGEXRFBMrtAG+Eo1btxHxo68HUsffzjKgyMavKnCWZ0aBqRUkTkBCknkuXf4+xPCcdOM5hV+jRr5SQs/UINbnruQeJG/8gyIoCRABeKB75z2Vzj9ZZh6/EvKuUmDbJoQ2Tn9WPSuWw==" Feb 10 15:08:57 volumio go-librespot[5701]: time="2026-02-10T15:08:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:08:57 volumio go-librespot[5701]: time="2026-02-10T15:08:57+07:00" level=debug msg="completed keyexchange" Feb 10 15:08:57 volumio go-librespot[5701]: time="2026-02-10T15:08:57+07:00" level=debug msg="completed challenge" Feb 10 15:08:57 volumio go-librespot[5701]: time="2026-02-10T15:08:57+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 10 15:08:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:08:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:08:57 volumio volumio[5627]: Starting albumart workers Feb 10 15:08:58 volumio volumio[5628]: Starting albumart workers Feb 10 15:08:58 volumio volumio[5626]: Starting albumart workers Feb 10 15:08:58 volumio volumio[5510]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 15:08:58 volumio volumio[5510]: info: [1770710938564] CoreMusicLibrary::Adding element YouTube Music Feb 10 15:08:58 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:08:58 volumio volumio[5510]: Cannot find translation for source YouTube Music Feb 10 15:08:58 volumio volumio[5510]: info: Volumio Calling Home Feb 10 15:08:58 volumio sudo[5732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 15:08:58 volumio sudo[5732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:58 volumio sudo[5732]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:59 volumio volumio[5510]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 15:08:59 volumio volumio[5510]: info: Discovery: Found device Volumio Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::volumioGetState Feb 10 15:08:59 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:59 volumio volumio[5510]: info: MPD Permissions set Feb 10 15:08:59 volumio volumio[5510]: info: MPD Permissions set Feb 10 15:08:59 volumio volumio[5510]: info: Upmpdcli Daemon Started Feb 10 15:08:59 volumio volumio[5510]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 15:08:59 volumio volumio[5510]: info: Discovery: Found device Volumio Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::volumioGetState Feb 10 15:08:59 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:08:59 volumio volumio[5510]: info: Volumio called home Feb 10 15:08:59 volumio volumio[5510]: info: Spotify config file written Feb 10 15:08:59 volumio volumio[5510]: 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 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio sudo[5738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 15:08:59 volumio sudo[5738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:08:59 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 15:08:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:08:59 volumio go-librespot[5751]: go-librespot daemon starting... Feb 10 15:08:59 volumio volumio[5510]: info: No need to fix Spotify hosts Feb 10 15:08:59 volumio sudo[5738]: pam_unix(sudo:session): session closed for user root Feb 10 15:08:59 volumio go-librespot[5757]: time="2026-02-10T15:08:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:08:59 volumio go-librespot[5757]: time="2026-02-10T15:08:59+07:00" level=debug msg="app state loaded" Feb 10 15:08:59 volumio go-librespot[5757]: time="2026-02-10T15:08:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:09:00 volumio go-librespot[5757]: time="2026-02-10T15:09:00+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 10 15:09:00 volumio go-librespot[5757]: time="2026-02-10T15:09:00+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 10 15:09:00 volumio go-librespot[5757]: time="2026-02-10T15:09:00+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 10 15:09:00 volumio go-librespot[5757]: time="2026-02-10T15:09:00+07:00" level=info msg="zeroconf server listening on port 42495" Feb 10 15:09:00 volumio go-librespot[5757]: time="2026-02-10T15:09:00+07:00" level=debug msg="obtained new client token: AAD5qthdXGhzd9HteU67hg5NcVnMApJoPN3K/tLGm1l2rTrTAhr4ZfzxjQ5VYGEf16Q1L4Qh1DMnLsdkNtn+mwbw7T3niYMHz1L5jSKkIKmUI12bO1AtVnKukZNSEsMILW6++bWsj+zsJ2fnQzsLbjlkmAXscF7CX2imppsbPh2JPUgLRAf5S3Xn9kse6d2yU+EdRkcMZ5LaPJq5HPVagUVgHal3f3PDY8JnTXoPhcy/eA3NuKhgC6eDeg==" Feb 10 15:09:00 volumio go-librespot[5757]: time="2026-02-10T15:09:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:09:00 volumio volumio[5510]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 15:09:00 volumio volumio[5510]: SPOTIFY: BQBsQZdqr3LyX9S0s_fDncmRepXLCFFXuk5Fi1lQm6r7g4Kcu7WVR-5vHal7jcpKpEbrOgw3ioq_BdFhin0KBhoUzLw-gyx4Wiw8quXaqbHXLOrUsTwVtr_Zs_NnDMgDL0PDs3_l97i6BKqo3AjGaJFnVF8Ik4cYLDMTkC85SOy7lfY4DNWUDSX8CSDMray6QGAGRxojT4EoUNgd-YoP2FnYofuR_O1zE6jO-Dbz7Wj1RQT9vMWRMrrMJJoNvUxDsivZHVtEn4XHLSo1YRw2fTth4F9j3tVgvxeXa6N86muKicX3oCdMMMfg Feb 10 15:09:00 volumio volumio[5510]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 15:09:00 volumio volumio[5510]: info: New Spotify access token = BQBsQZdqr3LyX9S0s_fDncmRepXLCFFXuk5Fi1lQm6r7g4Kcu7WVR-5vHal7jcpKpEbrOgw3ioq_BdFhin0KBhoUzLw-gyx4Wiw8quXaqbHXLOrUsTwVtr_Zs_NnDMgDL0PDs3_l97i6BKqo3AjGaJFnVF8Ik4cYLDMTkC85SOy7lfY4DNWUDSX8CSDMray6QGAGRxojT4EoUNgd-YoP2FnYofuR_O1zE6jO-Dbz7Wj1RQT9vMWRMrrMJJoNvUxDsivZHVtEn4XHLSo1YRw2fTth4F9j3tVgvxeXa6N86muKicX3oCdMMMfg Feb 10 15:09:00 volumio volumio[5510]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 15:09:01 volumio volumio[5510]: info: Starting Shairport Sync Feb 10 15:09:01 volumio go-librespot[5757]: time="2026-02-10T15:09:01+07:00" level=debug msg="completed keyexchange" Feb 10 15:09:01 volumio go-librespot[5757]: time="2026-02-10T15:09:01+07:00" level=debug msg="completed challenge" Feb 10 15:09:01 volumio volumio[5510]: info: Starting Shairport Sync Feb 10 15:09:01 volumio volumio[5510]: info: Starting Shairport Sync Feb 10 15:09:01 volumio go-librespot[5757]: time="2026-02-10T15:09:01+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 10 15:09:01 volumio sudo[5781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 15:09:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:09:01 volumio sudo[5781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:09:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:09:01 volumio sudo[5783]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 15:09:01 volumio sudo[5783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:09:01 volumio sudo[5785]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 15:09:01 volumio sudo[5785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:09:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 15:09:01 volumio volumio[5510]: info: CoreCommandRouter::volumioGetState Feb 10 15:09:01 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:09:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 15:09:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 15:09:01 volumio systemd[1]: shairport-sync.service: Consumed 2.333s CPU time. Feb 10 15:09:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 15:09:01 volumio sudo[5783]: pam_unix(sudo:session): session closed for user root Feb 10 15:09:01 volumio sudo[5785]: pam_unix(sudo:session): session closed for user root Feb 10 15:09:01 volumio sudo[5781]: pam_unix(sudo:session): session closed for user root Feb 10 15:09:01 volumio volumio[5510]: info: Shairport-Sync Started Feb 10 15:09:01 volumio volumio[5510]: Error adding Membership: Error: addMembership EINVAL Feb 10 15:09:01 volumio volumio[5510]: info: Shairport-Sync Started Feb 10 15:09:01 volumio volumio[5510]: info: Shairport-Sync Started Feb 10 15:09:01 volumio volumio[5510]: 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 10 15:09:01 volumio volumio[5510]: info: Spotify Successfully logged in Feb 10 15:09:01 volumio volumio[5510]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 15:09:01 volumio volumio[5510]: info: [1770710941762] CoreMusicLibrary::Adding element Spotify Feb 10 15:09:01 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 15:09:01 volumio volumio[5510]: Cannot find translation for source YouTube Music Feb 10 15:09:01 volumio volumio[5510]: Cannot find translation for source Spotify Feb 10 15:09:02 volumio volumio[5510]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 15:09:02 volumio volumio[5510]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 15:09:02 volumio volumio[5510]: info: VolumeController:: Volume=100 Mute =false Feb 10 15:09:02 volumio volumio[5510]: info: CoreCommandRouter::volumioGetState Feb 10 15:09:02 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:09:02 volumio volumio[5510]: info: CoreStateMachine::pushState Feb 10 15:09:02 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:09:02 volumio volumio[5510]: info: CoreCommandRouter::volumioPushState Feb 10 15:09:03 volumio volumio[5510]: info: go-librespot daemon successfully initialized Feb 10 15:09:04 volumio mpd[5730]: 2026-02-10T15:09:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 15:09:04 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 15:09:04 volumio sudo[5683]: pam_unix(sudo:session): session closed for user root Feb 10 15:09:04 volumio sudo[5693]: pam_unix(sudo:session): session closed for user root Feb 10 15:09:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 10 15:09:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:09:04 volumio volumio[5510]: error: MPD error: The expression evaluated to a falsy value: Feb 10 15:09:04 volumio volumio[5510]: assert.ok(self.idling) Feb 10 15:09:04 volumio volumio[5510]: error: The expression evaluated to a falsy value: Feb 10 15:09:04 volumio volumio[5510]: assert.ok(self.idling) Feb 10 15:09:04 volumio volumio[5510]: info: MPD running with PID5730 Feb 10 15:09:04 volumio volumio[5510]: ,establishing connection Feb 10 15:09:04 volumio volumio[5510]: error: updateQueue error: null Feb 10 15:09:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:09:04 volumio go-librespot[5827]: go-librespot daemon starting... Feb 10 15:09:04 volumio go-librespot[5828]: time="2026-02-10T15:09:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:09:04 volumio go-librespot[5828]: time="2026-02-10T15:09:04+07:00" level=debug msg="app state loaded" Feb 10 15:09:04 volumio go-librespot[5828]: time="2026-02-10T15:09:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:09:04 volumio volumio[5510]: info: Completed starting Core Plugins Feb 10 15:09:04 volumio volumio[5510]: info: ------------------------------------------- Feb 10 15:09:04 volumio volumio[5510]: info: ----- MyVolumio plugins startup ---- Feb 10 15:09:04 volumio volumio[5510]: info: ------------------------------------------- Feb 10 15:09:04 volumio volumio[5510]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 15:09:04 volumio volumio[5510]: error: updateQueue error: null Feb 10 15:09:04 volumio go-librespot[5828]: time="2026-02-10T15:09:04+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 10 15:09:04 volumio go-librespot[5828]: time="2026-02-10T15:09:04+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 10 15:09:04 volumio go-librespot[5828]: time="2026-02-10T15:09:04+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 10 15:09:04 volumio go-librespot[5828]: time="2026-02-10T15:09:04+07:00" level=info msg="zeroconf server listening on port 44957" Feb 10 15:09:05 volumio go-librespot[5828]: time="2026-02-10T15:09:05+07:00" level=debug msg="obtained new client token: AAC07ehehjuOCnQBidDmHSS9kptQl7F2kdVK3dyLyteR28KL4muINgXs16/AyrF5U5JbM4r5XXqCoNQXo56qHWihZAl+SnDpBy/Dlr3DxOt6QQeSys4rxM/hqlyTsJ20hsAr+MHOOJ1yiIttc3AxBmhjcjy8iU+Kj8yBhoD/CuAK8tQE6pz7MdizLAePb0ORzEvD2fGJ4Vm5UNOCuokoNZYk7fwRgTqegXjRy1ilmE9LYxog7g8c7RQ=" Feb 10 15:09:05 volumio go-librespot[5828]: time="2026-02-10T15:09:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:09:05 volumio go-librespot[5828]: time="2026-02-10T15:09:05+07:00" level=debug msg="completed keyexchange" Feb 10 15:09:05 volumio go-librespot[5828]: time="2026-02-10T15:09:05+07:00" level=debug msg="completed challenge" Feb 10 15:09:05 volumio go-librespot[5828]: time="2026-02-10T15:09:05+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 10 15:09:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:09:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:09:06 volumio volumio[5510]: info: Initializing connection to go-librespot Websocket Feb 10 15:09:06 volumio volumio[5510]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 15:09:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 10 15:09:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:09:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:09:08 volumio go-librespot[5836]: go-librespot daemon starting... Feb 10 15:09:08 volumio go-librespot[5837]: time="2026-02-10T15:09:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:09:08 volumio go-librespot[5837]: time="2026-02-10T15:09:08+07:00" level=debug msg="app state loaded" Feb 10 15:09:08 volumio go-librespot[5837]: time="2026-02-10T15:09:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:09:09 volumio go-librespot[5837]: time="2026-02-10T15:09:09+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 10 15:09:09 volumio go-librespot[5837]: time="2026-02-10T15:09:09+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 10 15:09:09 volumio go-librespot[5837]: time="2026-02-10T15:09:09+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 10 15:09:09 volumio go-librespot[5837]: time="2026-02-10T15:09:09+07:00" level=info msg="zeroconf server listening on port 40567" Feb 10 15:09:09 volumio volumio[5510]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 15:09:09 volumio go-librespot[5837]: time="2026-02-10T15:09:09+07:00" level=debug msg="obtained new client token: AAD9EHoFSodkbiLjrSK8sog9mSN853zx5L1YfB3l3tMBjpcIhp/agGxlozHr3EV1Da6YKaR/20+J3/H7cyd8BpxO9GzX4N9rMDwO6k5yqoIV1uqZq27gevvk5yHhIv3wnxY29RMyhSB8LlxFsWPFc9SI8jA9NvP2JJ9dS0kPIeSk6KazGeAofe3mftACfnim6grgRgG19nPfUVTywsh8atuRuJ3pos0Dk211hCJc9JC+fEVVTNmloXceWQ==" Feb 10 15:09:09 volumio go-librespot[5837]: time="2026-02-10T15:09:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:09:09 volumio go-librespot[5837]: time="2026-02-10T15:09:09+07:00" level=debug msg="completed keyexchange" Feb 10 15:09:09 volumio go-librespot[5837]: time="2026-02-10T15:09:09+07:00" level=debug msg="completed challenge" Feb 10 15:09:09 volumio go-librespot[5837]: time="2026-02-10T15:09:09+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 10 15:09:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:09:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:09:09 volumio volumio[5510]: info: Initializing connection to go-librespot Websocket Feb 10 15:09:09 volumio volumio[5510]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 15:09:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 10 15:09:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:09:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:09:12 volumio go-librespot[5844]: go-librespot daemon starting... Feb 10 15:09:12 volumio go-librespot[5845]: time="2026-02-10T15:09:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:09:12 volumio go-librespot[5845]: time="2026-02-10T15:09:12+07:00" level=debug msg="app state loaded" Feb 10 15:09:12 volumio go-librespot[5845]: time="2026-02-10T15:09:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:09:12 volumio volumio[5510]: info: Initializing connection to go-librespot Websocket Feb 10 15:09:12 volumio go-librespot[5845]: time="2026-02-10T15:09:12+07:00" level=debug msg="new websocket client" Feb 10 15:09:12 volumio volumio[5510]: info: Connection to go-librespot Websocket established Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 15:09:13 volumio volumio[5510]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 15:09:13 volumio volumio[5510]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 15:09:13 volumio volumio[5510]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 15:09:13 volumio volumio[5510]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 15:09:13 volumio volumio[5510]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 15:09:13 volumio volumio[5510]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 15:09:13 volumio volumio[5510]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 15:09:13 volumio volumio[5510]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 15:09:13 volumio go-librespot[5845]: time="2026-02-10T15:09:13+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 10 15:09:13 volumio go-librespot[5845]: time="2026-02-10T15:09:13+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 10 15:09:13 volumio go-librespot[5845]: time="2026-02-10T15:09:13+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 10 15:09:13 volumio go-librespot[5845]: time="2026-02-10T15:09:13+07:00" level=info msg="zeroconf server listening on port 43633" Feb 10 15:09:13 volumio go-librespot[5845]: time="2026-02-10T15:09:13+07:00" level=debug msg="obtained new client token: AACai/T5jzGVdwsTYh8F9zh7D1xuRzlfj8n2kJru1JZ1NCFSJt+FQ6ICJGgbESUNs5jp2nbC/SqWOVnBkuCRaxo7tk3YhZTMgHH2UUcKzXEx/qfLHF9vtJplxE8UpW6EcxpbDgamNWQ+h9vDomTYoQyL8D2MgZEfvwJwhQ7d2EKFSJbCAaVZO4m5Q2sgNvELmUYh+Pc9dlrh0/HwtREl07HgqWPaGZgP6uWZZ7ZoTsJ2CN908yzm3PhlRA==" Feb 10 15:09:13 volumio go-librespot[5845]: time="2026-02-10T15:09:13+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 10 15:09:13 volumio go-librespot[5845]: time="2026-02-10T15:09:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 15:09:13 volumio go-librespot[5845]: time="2026-02-10T15:09:13+07:00" level=debug msg="completed keyexchange" Feb 10 15:09:13 volumio go-librespot[5845]: time="2026-02-10T15:09:13+07:00" level=debug msg="completed challenge" Feb 10 15:09:13 volumio go-librespot[5845]: time="2026-02-10T15:09:13+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 10 15:09:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:09:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:09:15 volumio volumio[5510]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 15:09:15 volumio volumio[5510]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 15:09:15 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:09:15 volumio volumio[5510]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 15:09:15 volumio volumio[5510]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 15:09:15 volumio volumio[5510]: info: MyVolumio login type: Token Feb 10 15:09:15 volumio volumio[5510]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 15:09:15 volumio volumio[5510]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 15:09:16 volumio volumio[5510]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 15:09:16 volumio volumio[5510]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 15:09:16 volumio volumio[5510]: info: Streaming services startup Feb 10 15:09:16 volumio volumio[5510]: info: Starting Streaming Daemon Feb 10 15:09:17 volumio sudo[5869]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 15:09:17 volumio sudo[5869]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 15:09:17 volumio volumio[5510]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 15:09:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 10 15:09:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:09:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 15:09:17 volumio go-librespot[5875]: go-librespot daemon starting... Feb 10 15:09:17 volumio sudo[5869]: pam_unix(sudo:session): session closed for user root Feb 10 15:09:17 volumio go-librespot[5876]: time="2026-02-10T15:09:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 15:09:17 volumio go-librespot[5876]: time="2026-02-10T15:09:17+07:00" level=debug msg="app state loaded" Feb 10 15:09:17 volumio volumio[5510]: info: Getting Spotify volume Feb 10 15:09:17 volumio go-librespot[5876]: time="2026-02-10T15:09:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 15:09:17 volumio volumio[5510]: info: Connection to go-librespot Websocket closed Feb 10 15:09:17 volumio volumio[5510]: error: Cannot start Volumio Streaming Daemon Feb 10 15:09:17 volumio volumio[5510]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 15:09:17 volumio volumio[5510]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 15:09:17 volumio volumio[5510]: 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 10 15:09:17 volumio volumio[5510]: info: CoreCommandRouter::volumioGetState Feb 10 15:09:17 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:09:17 volumio volumio[5510]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 10 15:09:17 volumio volumio[5510]: SPOTIFY: SPOTIFY VOLUME undefined Feb 10 15:09:17 volumio volumio[5510]: SPOTIFY: VOLUMIO VOLUME 100 Feb 10 15:09:17 volumio volumio[5510]: info: Aligning Spotify Volume to Volumio Volume Feb 10 15:09:17 volumio volumio[5510]: info: CoreCommandRouter::volumioGetState Feb 10 15:09:17 volumio volumio[5510]: info: CorePlayQueue::getTrack 0 Feb 10 15:09:17 volumio volumio[5510]: info: Setting Spotify Volume from Volumio: 100 Feb 10 15:09:17 volumio go-librespot[5876]: time="2026-02-10T15:09:17+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 10 15:09:17 volumio go-librespot[5876]: time="2026-02-10T15:09:17+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 10 15:09:17 volumio go-librespot[5876]: time="2026-02-10T15:09:17+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 10 15:09:17 volumio go-librespot[5876]: time="2026-02-10T15:09:17+07:00" level=info msg="zeroconf server listening on port 33733" Feb 10 15:09:18 volumio go-librespot[5876]: time="2026-02-10T15:09:18+07:00" level=debug msg="obtained new client token: AAAYdLAiJB8erRl2WJgUERzuQ051E/rUEq+9puJ3F5ZosZqZmJ/4HwnoVUEoh50h8oYvd4c1sXgALZ1yB+RwQE7NCsgP9fPU2ypSoBavVQO6f3Pw3zH2rQP2fVr+2txxOFNtzekNxnrVCEZVmfiIxZQwgzW99IplUasVEbPVQxEWIoP+V1P7a1zlRqU6S57i+UwnxDS5oVojbZQIM489vBBn4WrgfoQANLZUvDj931L8JFZo5bJYjKhucw==" Feb 10 15:09:18 volumio go-librespot[5876]: time="2026-02-10T15:09:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 15:09:18 volumio volumio[5510]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 10 15:09:18 volumio go-librespot[5876]: time="2026-02-10T15:09:18+07:00" level=debug msg="completed keyexchange" Feb 10 15:09:18 volumio go-librespot[5876]: time="2026-02-10T15:09:18+07:00" level=debug msg="completed challenge" Feb 10 15:09:18 volumio go-librespot[5876]: time="2026-02-10T15:09:18+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 10 15:09:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 15:09:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 15:09:18 volumio volumio[5510]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 15:09:18 volumio volumio[5510]: Error: socket hang up Feb 10 15:09:18 volumio volumio[5510]: at connResetException (node:internal/errors:720:14) Feb 10 15:09:18 volumio volumio[5510]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 10 15:09:18 volumio volumio[5510]: at Socket.emit (node:events:526:35) Feb 10 15:09:18 volumio volumio[5510]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 10 15:09:18 volumio volumio[5510]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 10 15:09:18 volumio volumio[5510]: code: 'ECONNRESET', Feb 10 15:09:18 volumio volumio[5510]: response: undefined Feb 10 15:09:18 volumio volumio[5510]: } Feb 10 15:09:18 volumio volumio[5510]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 15:09:19 volumio sudo[5898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 15:08' Feb 10 15:09:19 volumio sudo[5898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"