Feb 17 22:23:00 volumio volumio[21054]: info: Loading plugin "network"... Feb 17 22:23:00 volumio volumio[21054]: info: Refreshing Cached IP Addresses Feb 17 22:23:00 volumio sudo[21090]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 22:23:00 volumio sudo[21090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:00 volumio volumio[21054]: info: Loading plugin "services"... Feb 17 22:23:00 volumio sudo[21090]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:00 volumio volumio[21054]: info: Loading plugin "alsa_controller"... Feb 17 22:23:00 volumio sudo[21092]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 22:23:00 volumio sudo[21092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:00 volumio sudo[21092]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:00 volumio sudo[21100]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 22:23:00 volumio sudo[21100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:01 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 22:23:01 volumio volumio[21054]: info: Loading plugin "wizard"... Feb 17 22:23:01 volumio volumio[21054]: info: Loading plugin "networkfs"... Feb 17 22:23:01 volumio volumio[21054]: info: Starting Udev Watcher for removable devices Feb 17 22:23:01 volumio volumio[21054]: info: Ignoring mount for partition: boot Feb 17 22:23:01 volumio volumio[21054]: info: Ignoring mount for partition: volumio Feb 17 22:23:01 volumio volumio[21054]: info: Ignoring mount for partition: volumio_data Feb 17 22:23:01 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 22:23:01 volumio volumio[21054]: info: Loading plugin "volumio_command_line_client"... Feb 17 22:23:01 volumio volumio[21054]: info: Loading plugin "upnp"... Feb 17 22:23:01 volumio volumio[21054]: info: [1771341781195] Starting Upmpd Daemon Feb 17 22:23:01 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 22:23:01 volumio volumio[21054]: info: Loading plugin "my_music"... Feb 17 22:23:01 volumio volumio[21054]: info: Loading plugin "mpd"... Feb 17 22:23:01 volumio volumio[21054]: info: Loading plugin "upnp_browser"... Feb 17 22:23:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 17 22:23:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:02 volumio go-librespot[21123]: go-librespot daemon starting... Feb 17 22:23:02 volumio go-librespot[21124]: time="2026-02-17T22:23:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:02 volumio go-librespot[21124]: time="2026-02-17T22:23:02+07:00" level=debug msg="app state loaded" Feb 17 22:23:02 volumio go-librespot[21124]: time="2026-02-17T22:23:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:02 volumio go-librespot[21124]: time="2026-02-17T22:23:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:23:02 volumio go-librespot[21124]: time="2026-02-17T22:23:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 22:23:02 volumio go-librespot[21124]: time="2026-02-17T22:23:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 22:23:02 volumio go-librespot[21124]: time="2026-02-17T22:23:02+07:00" level=info msg="zeroconf server listening on port 34425" Feb 17 22:23:03 volumio go-librespot[21124]: time="2026-02-17T22:23:03+07:00" level=debug msg="obtained new client token: AAAz3c0DpnH3FiWTE0PcPP6mo/R33M/PFuX0/ZhqWm4xGlgk2mDBuva+kSa+NS58kIUxdCReVDhXJB+cMEAEuYC0pG1wmTfGBuoy49evGIZjqitD4zjeu/NAeCCJ6lPbcuggBW/6W5EhNTS5bf8s6/utMDYvIhZiAxW6a0xG75h225dZ5LRUFX84ieqwbzc1uugS3ZsZ85c0x8BDHuSpeXWg3abEPIsLdRZlGDMPsB107wnFplDp8SY=" Feb 17 22:23:03 volumio go-librespot[21124]: time="2026-02-17T22:23:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:03 volumio go-librespot[21124]: time="2026-02-17T22:23:03+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 17 22:23:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:03 volumio sudo[21100]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:04 volumio volumio[21054]: info: Starting UPNP Browser Feb 17 22:23:04 volumio volumio[21054]: info: Loading plugin "alarm-clock"... Feb 17 22:23:05 volumio volumio[21054]: info: Loading plugin "airplay_emulation"... Feb 17 22:23:05 volumio volumio[21054]: info: Starting Shairport Sync Feb 17 22:23:05 volumio volumio[21054]: info: Loading plugin "last_100"... Feb 17 22:23:05 volumio volumio[21054]: info: Loading plugin "webradio"... Feb 17 22:23:05 volumio volumio[21054]: info: Loading plugin "i2s_dacs"... Feb 17 22:23:05 volumio volumio[21054]: info: Loading plugin "volumiodiscovery"... Feb 17 22:23:05 volumio volumio[21054]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 22:23:05 volumio volumio[21054]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:23:05 volumio volumio[21054]: *** WARNING *** For more information see Feb 17 22:23:05 volumio volumio[21054]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 22:23:05 volumio volumio[21054]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:23:05 volumio volumio[21054]: *** WARNING *** For more information see Feb 17 22:23:05 volumio node[21054]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 22:23:05 volumio node[21054]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:23:05 volumio node[21054]: *** WARNING *** For more information see Feb 17 22:23:05 volumio node[21054]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 22:23:05 volumio node[21054]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:23:05 volumio node[21054]: *** WARNING *** For more information see Feb 17 22:23:05 volumio volumio[21054]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 22:23:05 volumio volumio[21054]: info: Discovery: Started advertising with name: Volumio Feb 17 22:23:05 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 22:23:05 volumio volumio[21054]: info: Loading plugin "spop"... Feb 17 22:23:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 17 22:23:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:06 volumio go-librespot[21134]: go-librespot daemon starting... Feb 17 22:23:06 volumio go-librespot[21135]: time="2026-02-17T22:23:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:06 volumio go-librespot[21135]: time="2026-02-17T22:23:06+07:00" level=debug msg="app state loaded" Feb 17 22:23:06 volumio go-librespot[21135]: time="2026-02-17T22:23:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:07 volumio go-librespot[21135]: time="2026-02-17T22:23:07+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 17 22:23:07 volumio go-librespot[21135]: time="2026-02-17T22:23:07+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 17 22:23:07 volumio go-librespot[21135]: time="2026-02-17T22:23:07+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 17 22:23:07 volumio go-librespot[21135]: time="2026-02-17T22:23:07+07:00" level=info msg="zeroconf server listening on port 34365" Feb 17 22:23:07 volumio volumio[21054]: info: Loading plugin "ytcr"... Feb 17 22:23:07 volumio go-librespot[21135]: time="2026-02-17T22:23:07+07:00" level=debug msg="obtained new client token: AAAeUIZFnGzt1KLU63Yv6AD3J2NFRHOxOUV5h7wbpl/73in+lllavL4qmbZ/IPGEBnAFQStw8bZAG29KkZxWuQTB5sTuTdmA8/uKOF1hxQwNIOfsXTw1mko0Hw5CDJc/T07zdgJI3OP5nPjeYKBQpuXWPmY8jpIOQM7NmXhT07hia4Hej/kB4jRmZPnzSQJ/a8kHlXRul9PpZ/wJ6f7G0BpRweL6A36ibQqVYOwYhx1QSFHCrIBezEfTNA==" Feb 17 22:23:07 volumio go-librespot[21135]: time="2026-02-17T22:23:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:07 volumio go-librespot[21135]: time="2026-02-17T22:23:07+07:00" level=debug msg="completed keyexchange" Feb 17 22:23:07 volumio go-librespot[21135]: time="2026-02-17T22:23:07+07:00" level=debug msg="completed challenge" Feb 17 22:23:07 volumio go-librespot[21135]: time="2026-02-17T22:23:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 22:23:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:09 volumio volumio[21054]: info: Loading plugin "ytmusic"... Feb 17 22:23:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 17 22:23:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:10 volumio go-librespot[21144]: go-librespot daemon starting... Feb 17 22:23:10 volumio volumio-remote-updater[25144]: [2026-02-17 22:23:10] [connect] Successful connection Feb 17 22:23:10 volumio go-librespot[21145]: time="2026-02-17T22:23:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:10 volumio go-librespot[21145]: time="2026-02-17T22:23:10+07:00" level=debug msg="app state loaded" Feb 17 22:23:10 volumio go-librespot[21145]: time="2026-02-17T22:23:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:11 volumio volumio[21054]: info: Loading plugin "outputs"... Feb 17 22:23:11 volumio volumio[21054]: info: Loading plugin "albumart"... Feb 17 22:23:11 volumio volumio[21054]: info: Plugin example_plugin is not enabled Feb 17 22:23:11 volumio volumio[21054]: info: Loading plugin "inputs"... Feb 17 22:23:11 volumio volumio[21054]: info: Loading plugin "updater_comm"... Feb 17 22:23:11 volumio volumio[21054]: info: Plugin mpdemulation is not enabled Feb 17 22:23:11 volumio volumio[21054]: info: Loading plugin "rest_api"... Feb 17 22:23:11 volumio volumio[21054]: info: Loading plugin "websocket"... Feb 17 22:23:11 volumio volumio[21054]: info: Starting Socket.io Server version 1.7.4 Feb 17 22:23:11 volumio volumio[21054]: info: Loading plugin "RoonBridge"... Feb 17 22:23:11 volumio go-librespot[21145]: time="2026-02-17T22:23:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:23:11 volumio go-librespot[21145]: time="2026-02-17T22:23:11+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 17 22:23:11 volumio go-librespot[21145]: time="2026-02-17T22:23:11+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 17 22:23:11 volumio go-librespot[21145]: time="2026-02-17T22:23:11+07:00" level=info msg="zeroconf server listening on port 37673" Feb 17 22:23:11 volumio go-librespot[21145]: time="2026-02-17T22:23:11+07:00" level=debug msg="obtained new client token: AAABsqU/W0SvkQjVxt7VVV3m1GBIWswZ9laMynYRIZqFiaQ6r1+bl/Q8fwRCnrN6/xJjMJqaAn4sNibsygum8sWjDagM/7APEdAiYPv1KAgrNxNXxR0WeFQVQFaQznORrjygKQ2CHT8sQnZWK7spE0oi+cf7gKS8TBfIqwf5w9BAlCq7OE6wWFKfgVhmtyT2kCR/C8zRxaVSDmO+sKMpuZL/rk6XIRQxoSObmK/itUx+9hLn3CkRkos/eA==" Feb 17 22:23:11 volumio go-librespot[21145]: time="2026-02-17T22:23:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:11 volumio go-librespot[21145]: time="2026-02-17T22:23:11+07:00" level=debug msg="completed keyexchange" Feb 17 22:23:11 volumio go-librespot[21145]: time="2026-02-17T22:23:11+07:00" level=debug msg="completed challenge" Feb 17 22:23:11 volumio volumio[21054]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 22:23:12 volumio volumio[21054]: info: Loading i18n strings for locale en Feb 17 22:23:12 volumio volumio[21054]: Updating browse sources language Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:12 volumio go-librespot[21145]: time="2026-02-17T22:23:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 22:23:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::initPlayerControls Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:12 volumio volumio[21165]: Forking 3 albumart workers Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 22:23:12 volumio volumio[21054]: Express server listening on port 3000 Feb 17 22:23:12 volumio volumio[21054]: [Metrics] WebUI: 16s 53.62ms Feb 17 22:23:12 volumio volumio[21054]: info: CoreStateMachine::resetVolumioState Feb 17 22:23:12 volumio volumio[21054]: info: CoreStateMachine::getcurrentVolume Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 22:23:12 volumio sudo[21208]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 22:23:12 volumio sudo[21208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:12 volumio sudo[21208]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:12 volumio sudo[21210]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 22:23:12 volumio sudo[21210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:12 volumio volumio[21054]: info: Volumio Network Manager: Network status updated: 1 Feb 17 22:23:12 volumio sudo[21210]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:12 volumio volumio[21054]: info: VolumeController:: Volume=100 Mute =false Feb 17 22:23:12 volumio volumio[21054]: info: CoreStateMachine::pushState Feb 17 22:23:12 volumio volumio[21054]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::volumioPushState Feb 17 22:23:12 volumio volumio[21054]: info: CoreStateMachine::updateTrackBlock Feb 17 22:23:12 volumio volumio[21054]: info: CorePlayQueue::getTrackBlock Feb 17 22:23:12 volumio volumio[21054]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 22:23:13 volumio volumio-remote-updater[25144]: [2026-02-17 22:23:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771341790 101 Feb 17 22:23:13 volumio volumio[21054]: 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 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:13 volumio volumio[21054]: info: Reloading queue from file Feb 17 22:23:13 volumio volumio[21054]: info: CoreStateMachine::setRepeat null single undefined Feb 17 22:23:13 volumio volumio[21054]: info: CoreStateMachine::pushState Feb 17 22:23:13 volumio volumio[21054]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::volumioPushState Feb 17 22:23:13 volumio volumio[21054]: info: CoreStateMachine::setRandom null Feb 17 22:23:13 volumio volumio[21054]: info: CoreStateMachine::pushState Feb 17 22:23:13 volumio volumio[21054]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::volumioPushState Feb 17 22:23:13 volumio volumio[21054]: info: Setting Device type: Raspberry PI Feb 17 22:23:13 volumio volumio[21054]: info: Completed loading Core Plugins Feb 17 22:23:13 volumio volumio[21054]: info: Preparing to generate the ALSA configuration file Feb 17 22:23:13 volumio volumio[21054]: info: VolumeController:: Volume=100 Mute =false Feb 17 22:23:13 volumio volumio[21054]: info: CoreStateMachine::pushState Feb 17 22:23:13 volumio volumio[21054]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::volumioPushState Feb 17 22:23:13 volumio volumio[21054]: info: Asound.conf file unchanged, so no further update is needed Feb 17 22:23:13 volumio volumio[21054]: info: Output device has changed, restarting MPD Feb 17 22:23:13 volumio volumio[21054]: info: Output device has changed, restarting Shairport Sync Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:13 volumio sudo[21227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 22:23:13 volumio sudo[21227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:13 volumio volumio[21054]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 22:23:13 volumio volumio[21054]: info: ___________ START PLUGINS ___________ Feb 17 22:23:13 volumio sudo[21229]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 22:23:13 volumio volumio[21054]: info: ControllerMpd::onStart: Initializing MPD Feb 17 22:23:13 volumio volumio[21054]: info: Creating MPD Configuration file Feb 17 22:23:13 volumio sudo[21229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:13 volumio sudo[21231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 22:23:13 volumio sudo[21231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:13 volumio sudo[21229]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:23:13 volumio volumio[21054]: info: [1771341793618] CoreMusicLibrary::Adding element Media Servers Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:13 volumio sudo[21227]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:13 volumio volumio[21054]: info: UPNP Browser: Client initialized successfully Feb 17 22:23:13 volumio sudo[21240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 22:23:13 volumio sudo[21240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:13 volumio sudo[21242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 22:23:13 volumio sudo[21242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:13 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 22:23:13 volumio sudo[21240]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:13 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 22:23:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 22:23:13 volumio systemd[1]: mpd.service: Consumed 7.039s CPU time. Feb 17 22:23:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 22:23:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 22:23:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 22:23:13 volumio volumio[21054]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 22:23:13 volumio volumio[21054]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 22:23:13 volumio volumio[21054]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:23:13 volumio volumio[21054]: info: [1771341793998] CoreMusicLibrary::Adding element Last_100 Feb 17 22:23:14 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 22:23:14 volumio volumio[21054]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:23:14 volumio volumio[21054]: info: [1771341794012] CoreMusicLibrary::Adding element Webradio Feb 17 22:23:14 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:14 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 22:23:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 22:23:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 22:23:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 22:23:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 22:23:14 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 22:23:14 volumio volumio[21054]: info: Initializing BBC Radios Feb 17 22:23:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 22:23:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 22:23:14 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 22:23:14 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:14 volumio volumio[21054]: info: Creating Spotify config file Feb 17 22:23:14 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:14 volumio sudo[21261]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 22:23:14 volumio sudo[21261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 22:23:14 volumio sudo[21261]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:15 volumio volumio[21178]: Starting albumart workers Feb 17 22:23:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 17 22:23:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:15 volumio go-librespot[21272]: go-librespot daemon starting... Feb 17 22:23:15 volumio go-librespot[21273]: time="2026-02-17T22:23:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:15 volumio volumio[21054]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:23:15 volumio volumio[21054]: info: [1771341795570] CoreMusicLibrary::Adding element YouTube Music Feb 17 22:23:15 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:15 volumio volumio[21054]: Cannot find translation for source YouTube Music Feb 17 22:23:15 volumio volumio[21054]: info: Volumio Calling Home Feb 17 22:23:15 volumio volumio[21176]: Starting albumart workers Feb 17 22:23:15 volumio sudo[21280]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 22:23:15 volumio sudo[21280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:15 volumio sudo[21280]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:16 volumio go-librespot[21273]: time="2026-02-17T22:23:16+07:00" level=info msg="zeroconf server listening on port 36295" Feb 17 22:23:16 volumio volumio[21181]: Starting albumart workers Feb 17 22:23:16 volumio volumio[21054]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 22:23:16 volumio volumio[21054]: info: Discovery: Found device Volumio Feb 17 22:23:16 volumio volumio[21054]: info: CoreCommandRouter::volumioGetState Feb 17 22:23:16 volumio volumio[21054]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:16 volumio volumio[21054]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 22:23:16 volumio volumio[21054]: info: Discovery: Found device Volumio Feb 17 22:23:16 volumio volumio[21054]: info: CoreCommandRouter::volumioGetState Feb 17 22:23:16 volumio volumio[21054]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:16 volumio volumio[21054]: info: MPD Permissions set Feb 17 22:23:16 volumio volumio[21054]: info: MPD Permissions set Feb 17 22:23:16 volumio volumio[21054]: info: Upmpdcli Daemon Started Feb 17 22:23:16 volumio volumio[21054]: info: Volumio called home Feb 17 22:23:16 volumio volumio[21054]: info: Spotify config file written Feb 17 22:23:17 volumio sudo[21288]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 22:23:17 volumio sudo[21288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:17 volumio volumio[21054]: 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 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 22:23:17 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 22:23:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:17 volumio go-librespot[21301]: go-librespot daemon starting... Feb 17 22:23:17 volumio sudo[21288]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:17 volumio volumio[21054]: info: No need to fix Spotify hosts Feb 17 22:23:17 volumio go-librespot[21304]: time="2026-02-17T22:23:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:17 volumio go-librespot[21304]: time="2026-02-17T22:23:17+07:00" level=debug msg="app state loaded" Feb 17 22:23:17 volumio go-librespot[21304]: time="2026-02-17T22:23:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:18 volumio go-librespot[21304]: time="2026-02-17T22:23: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 17 22:23:18 volumio go-librespot[21304]: time="2026-02-17T22:23: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 17 22:23:18 volumio go-librespot[21304]: time="2026-02-17T22:23: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 17 22:23:18 volumio go-librespot[21304]: time="2026-02-17T22:23:18+07:00" level=info msg="zeroconf server listening on port 36487" Feb 17 22:23:18 volumio volumio[21054]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 22:23:18 volumio volumio[21054]: SPOTIFY: BQBlu3Pe6d13oToIvOsZfb45j0WHU4NcmHn2YObAZomEgVgk769F73re2s9PiobVucwkesybkAhp1lX2EkiP_NyUR3dDwzNZtBXT19oUEXKmaYX3g1Tyw5yAQfbKgNLZ7z8VERT_kowNQaeHmO9MHbstE2zxTCWKEN0VMZvcBSFSNgkpTPrjaFsvHfLsFUb7pfiyqm_Dn8cMVKAtz9iaXarNRJfFnSsF_MGx8XZIVmw1qshP4wZbY2PzBzKV0mEJSWLG_vzdNdBzCOLuQt06048lo24qRpAEUI7BeQLjhjhehN_rA61pr3-6 Feb 17 22:23:18 volumio volumio[21054]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 22:23:18 volumio volumio[21054]: info: New Spotify access token = BQBlu3Pe6d13oToIvOsZfb45j0WHU4NcmHn2YObAZomEgVgk769F73re2s9PiobVucwkesybkAhp1lX2EkiP_NyUR3dDwzNZtBXT19oUEXKmaYX3g1Tyw5yAQfbKgNLZ7z8VERT_kowNQaeHmO9MHbstE2zxTCWKEN0VMZvcBSFSNgkpTPrjaFsvHfLsFUb7pfiyqm_Dn8cMVKAtz9iaXarNRJfFnSsF_MGx8XZIVmw1qshP4wZbY2PzBzKV0mEJSWLG_vzdNdBzCOLuQt06048lo24qRpAEUI7BeQLjhjhehN_rA61pr3-6 Feb 17 22:23:18 volumio volumio[21054]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 22:23:18 volumio volumio[21054]: info: Starting Shairport Sync Feb 17 22:23:18 volumio volumio[21054]: info: Starting Shairport Sync Feb 17 22:23:18 volumio volumio[21054]: info: Starting Shairport Sync Feb 17 22:23:18 volumio sudo[21328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 22:23:18 volumio sudo[21328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:18 volumio go-librespot[21304]: time="2026-02-17T22:23:18+07:00" level=debug msg="obtained new client token: AAA1txrMQ0DvaUv6Yw+qHK8PosfB5oeJFMGzHYzBYCCBSCMaszb0FUx8fg9J26/6NnobUS3x42OFKJ/fWm1ku0C+o/kfbAKHwxo0WQWjZeFUg22f3BAuoDOnmf2yvJRAMYOvZIhX8jx7och+3Ku0VLOPEFp64j9euYWVBejrB1NtF8AChNmzq5bl4jnSsVELYuWO0ExmSsuGJaDBU2rP5RSDVmFxfiVmaRAtyIWG/Qb5gNVUISssPlQ/uw==" Feb 17 22:23:18 volumio sudo[21330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 22:23:18 volumio sudo[21330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:18 volumio sudo[21332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 22:23:18 volumio sudo[21332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:18 volumio go-librespot[21304]: time="2026-02-17T22:23:18+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 17 22:23:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 22:23:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 22:23:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 22:23:18 volumio systemd[1]: shairport-sync.service: Consumed 2.223s CPU time. Feb 17 22:23:18 volumio go-librespot[21304]: time="2026-02-17T22:23:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 22:23:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 22:23:18 volumio sudo[21328]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:18 volumio go-librespot[21304]: time="2026-02-17T22:23:18+07:00" level=debug msg="completed keyexchange" Feb 17 22:23:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 22:23:18 volumio go-librespot[21304]: time="2026-02-17T22:23:18+07:00" level=debug msg="completed challenge" Feb 17 22:23:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 22:23:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 22:23:18 volumio volumio[21054]: info: Shairport-Sync Started Feb 17 22:23:18 volumio volumio[21054]: Error adding Membership: Error: addMembership EINVAL Feb 17 22:23:19 volumio volumio[21054]: info: CoreCommandRouter::volumioGetState Feb 17 22:23:19 volumio volumio[21054]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 22:23:19 volumio go-librespot[21304]: time="2026-02-17T22:23:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 22:23:19 volumio sudo[21330]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:19 volumio sudo[21332]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:19 volumio volumio[21054]: info: Shairport-Sync Started Feb 17 22:23:19 volumio volumio[21054]: info: Shairport-Sync Started Feb 17 22:23:19 volumio volumio[21054]: 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 17 22:23:19 volumio volumio[21054]: info: Spotify Successfully logged in Feb 17 22:23:19 volumio volumio[21054]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:23:19 volumio volumio[21054]: info: [1771341799443] CoreMusicLibrary::Adding element Spotify Feb 17 22:23:19 volumio volumio[21054]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:19 volumio volumio[21054]: Cannot find translation for source YouTube Music Feb 17 22:23:19 volumio volumio[21054]: Cannot find translation for source Spotify Feb 17 22:23:20 volumio volumio[21054]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 22:23:20 volumio volumio[21054]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 22:23:20 volumio volumio[21054]: info: VolumeController:: Volume=100 Mute =false Feb 17 22:23:20 volumio volumio[21054]: info: CoreCommandRouter::volumioGetState Feb 17 22:23:20 volumio volumio[21054]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:20 volumio volumio[21054]: info: CoreStateMachine::pushState Feb 17 22:23:20 volumio volumio[21054]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:20 volumio volumio[21054]: info: CoreCommandRouter::volumioPushState Feb 17 22:23:21 volumio volumio[21054]: info: go-librespot daemon successfully initialized Feb 17 22:23:21 volumio mpd[21271]: 2026-02-17T22:23:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 22:23:21 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 22:23:21 volumio sudo[21231]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:21 volumio sudo[21242]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:22 volumio volumio[21054]: error: MPD error: The expression evaluated to a falsy value: Feb 17 22:23:22 volumio volumio[21054]: assert.ok(self.idling) Feb 17 22:23:22 volumio volumio[21054]: error: The expression evaluated to a falsy value: Feb 17 22:23:22 volumio volumio[21054]: assert.ok(self.idling) Feb 17 22:23:22 volumio volumio[21054]: error: updateQueue error: null Feb 17 22:23:22 volumio volumio[21054]: info: MPD running with PID21271 Feb 17 22:23:22 volumio volumio[21054]: ,establishing connection Feb 17 22:23:22 volumio volumio[21054]: info: Completed starting Core Plugins Feb 17 22:23:22 volumio volumio[21054]: info: ------------------------------------------- Feb 17 22:23:22 volumio volumio[21054]: info: ----- MyVolumio plugins startup ---- Feb 17 22:23:22 volumio volumio[21054]: info: ------------------------------------------- Feb 17 22:23:22 volumio volumio[21054]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 22:23:22 volumio volumio[21054]: error: updateQueue error: null Feb 17 22:23:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 22:23:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:22 volumio go-librespot[21384]: go-librespot daemon starting... Feb 17 22:23:22 volumio go-librespot[21385]: time="2026-02-17T22:23:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:22 volumio go-librespot[21385]: time="2026-02-17T22:23:22+07:00" level=debug msg="app state loaded" Feb 17 22:23:22 volumio go-librespot[21385]: time="2026-02-17T22:23:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:22 volumio go-librespot[21385]: time="2026-02-17T22:23: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 17 22:23:22 volumio go-librespot[21385]: time="2026-02-17T22:23: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 17 22:23:22 volumio go-librespot[21385]: time="2026-02-17T22:23: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 17 22:23:22 volumio go-librespot[21385]: time="2026-02-17T22:23:22+07:00" level=info msg="zeroconf server listening on port 38459" Feb 17 22:23:23 volumio go-librespot[21385]: time="2026-02-17T22:23:23+07:00" level=debug msg="obtained new client token: AAAd2pEJsvkIbntdjr481oyT8rvGZquZMEjgZSw4Qkl1K/JtaColMEErlJhPotdqdI8G5Uos4AFR2Y6IvhbehtdxAlOguU+RbdwzAiDDG35YEITrbGSckdELgXsckkYSoNr/poyYkNWtaEXuFBD29/Yutds3itnrM2tAnnCcGxAjPjSNMMGow13Lev8wDjoo2Pwca62o9jUoGqprVFUZRyBudePdnYgP2a6+sMFe+HFbFnyNB2htTtM=" Feb 17 22:23:23 volumio go-librespot[21385]: time="2026-02-17T22:23:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:23 volumio go-librespot[21385]: time="2026-02-17T22:23:23+07:00" level=debug msg="completed keyexchange" Feb 17 22:23:23 volumio go-librespot[21385]: time="2026-02-17T22:23:23+07:00" level=debug msg="completed challenge" Feb 17 22:23:23 volumio go-librespot[21385]: time="2026-02-17T22:23:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 22:23:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:24 volumio volumio[21054]: info: Initializing connection to go-librespot Websocket Feb 17 22:23:24 volumio volumio[21054]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 22:23:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 22:23:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:26 volumio go-librespot[21393]: go-librespot daemon starting... Feb 17 22:23:26 volumio go-librespot[21394]: time="2026-02-17T22:23:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:26 volumio go-librespot[21394]: time="2026-02-17T22:23:26+07:00" level=debug msg="app state loaded" Feb 17 22:23:26 volumio go-librespot[21394]: time="2026-02-17T22:23:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:26 volumio volumio[21054]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 22:23:27 volumio go-librespot[21394]: time="2026-02-17T22:23:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:23:27 volumio go-librespot[21394]: time="2026-02-17T22:23:27+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 17 22:23:27 volumio go-librespot[21394]: time="2026-02-17T22:23:27+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 17 22:23:27 volumio go-librespot[21394]: time="2026-02-17T22:23:27+07:00" level=info msg="zeroconf server listening on port 45831" Feb 17 22:23:27 volumio volumio[21054]: info: Initializing connection to go-librespot Websocket Feb 17 22:23:27 volumio go-librespot[21394]: time="2026-02-17T22:23:27+07:00" level=debug msg="new websocket client" Feb 17 22:23:27 volumio volumio[21054]: info: Connection to go-librespot Websocket established Feb 17 22:23:27 volumio go-librespot[21394]: time="2026-02-17T22:23:27+07:00" level=debug msg="obtained new client token: AABaynaPDkdSEHqf5BSZ6W4x47b5mg5A5nBlEZlgokobKAc5XtR3PvpYuf/AaetCflMAJ7TwEZDNKtPgsehJzggjYEZYyaXsNPKugNFSukbkNkBqplZXhkKTCfPXQoeki3hNCjYGGQ1hFmLuyl0Ju4C4eWIjzabIvFwuIqPPDt3FcUcK4G86jxsZP6+TNAu1YRvGqQlOd6YPhnqbDuZZtlsAq0Srm1+1bbuXSITass98Iv+a5yAuLiFenA==" Feb 17 22:23:27 volumio go-librespot[21394]: time="2026-02-17T22:23:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:27 volumio go-librespot[21394]: time="2026-02-17T22:23:27+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 17 22:23:27 volumio volumio[21054]: info: Connection to go-librespot Websocket closed Feb 17 22:23:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:30 volumio volumio[21054]: info: Getting Spotify volume Feb 17 22:23:30 volumio volumio[21054]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 22:23:30 volumio volumio[21054]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 22:23:30 volumio volumio[21054]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 22:23:30 volumio volumio[21054]: errno: -111, Feb 17 22:23:30 volumio volumio[21054]: code: 'ECONNREFUSED', Feb 17 22:23:30 volumio volumio[21054]: syscall: 'connect', Feb 17 22:23:30 volumio volumio[21054]: address: '127.0.0.1', Feb 17 22:23:30 volumio volumio[21054]: port: 9879, Feb 17 22:23:30 volumio volumio[21054]: response: undefined Feb 17 22:23:30 volumio volumio[21054]: } Feb 17 22:23:30 volumio volumio[21054]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 22:23:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 22:23:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:30 volumio go-librespot[21413]: go-librespot daemon starting... Feb 17 22:23:30 volumio go-librespot[21414]: time="2026-02-17T22:23:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:30 volumio go-librespot[21414]: time="2026-02-17T22:23:30+07:00" level=debug msg="app state loaded" Feb 17 22:23:30 volumio go-librespot[21414]: time="2026-02-17T22:23:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:31 volumio go-librespot[21414]: time="2026-02-17T22:23: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:23:31 volumio go-librespot[21414]: time="2026-02-17T22:23:31+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 17 22:23:31 volumio go-librespot[21414]: time="2026-02-17T22:23:31+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 17 22:23:31 volumio go-librespot[21414]: time="2026-02-17T22:23:31+07:00" level=info msg="zeroconf server listening on port 36683" Feb 17 22:23:31 volumio go-librespot[21414]: time="2026-02-17T22:23:31+07:00" level=debug msg="obtained new client token: AADSRIhnXdHy0qcIYdRxX9LydDhMRLDr2OQdHQ6j9GsNC3MGsFpkjkH7mVBaUjupeCpcO5hV4W3FX3bgwh6d/hP59gI6wYJ9FZCnwzbULrKzvXCU4gPfSKh1D7lWnI0sHZNYaw48azZAT6vithndkH0i2z5AGZ+b+vmpSW4eHpiVtw/IGboMtj7P42G8SZGtPZGVjr+dAqwaHnakxiDwd6zx5Wj7PtoIH1/OXjNnaALhJDV3OxFKxZT35Q==" Feb 17 22:23:31 volumio go-librespot[21414]: time="2026-02-17T22:23:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:31 volumio go-librespot[21414]: time="2026-02-17T22:23:31+07:00" level=debug msg="completed keyexchange" Feb 17 22:23:31 volumio go-librespot[21414]: time="2026-02-17T22:23:31+07:00" level=debug msg="completed challenge" Feb 17 22:23:31 volumio go-librespot[21414]: time="2026-02-17T22:23: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 17 22:23:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:32 volumio sudo[21438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 22:22' Feb 17 22:23:32 volumio sudo[21438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:32 volumio sudo[21438]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:32 volumio volumio-remote-updater[25144]: [2026-02-17 22:23:32] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 22:23:32 volumio volumio-remote-updater[25144]: [2026-02-17 22:23:32] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 22:23:32 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:32 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 22:23:32 volumio systemd[1]: volumio.service: Consumed 49.236s CPU time. Feb 17 22:23:32 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 22:23:32 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 22:23:32 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20983. Feb 17 22:23:32 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 22:23:32 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 22:23:32 volumio systemd[1]: volumio.service: Consumed 49.236s CPU time. Feb 17 22:23:32 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 22:23:32 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 22:23:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 17 22:23:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:35 volumio go-librespot[21465]: go-librespot daemon starting... Feb 17 22:23:35 volumio go-librespot[21466]: time="2026-02-17T22:23:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:35 volumio go-librespot[21466]: time="2026-02-17T22:23:35+07:00" level=debug msg="app state loaded" Feb 17 22:23:35 volumio go-librespot[21466]: time="2026-02-17T22:23:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:35 volumio go-librespot[21466]: time="2026-02-17T22:23:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:23:35 volumio go-librespot[21466]: time="2026-02-17T22:23:35+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 17 22:23:35 volumio go-librespot[21466]: time="2026-02-17T22:23:35+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 17 22:23:35 volumio go-librespot[21466]: time="2026-02-17T22:23:35+07:00" level=info msg="zeroconf server listening on port 39827" Feb 17 22:23:36 volumio go-librespot[21466]: time="2026-02-17T22:23:36+07:00" level=debug msg="obtained new client token: AABpjoJsvsyoBDTxSgjsYiONzUsuvM509xYVRqcetNA+UDQRt1Pn35Kzo9lamxVPDyJ3Au1pxb7IUU2i28CVOxbFMSZP4U8n0L93FRut3x3nzp/p1HauBrkQDei6GCkR6LWpBsE4l3RxsGPbu2r+J1n2zXg9PMmd/dxP47BC3KqLpdopNsS7loJ5ls/FBRrEXlLwLIpYr3/SZfPNykCRpkSGxEiH8+m+OEsCLFH67fGg9WbiWJkKzjwbbw==" Feb 17 22:23:36 volumio go-librespot[21466]: time="2026-02-17T22:23:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:36 volumio go-librespot[21466]: time="2026-02-17T22:23:36+07:00" level=debug msg="completed keyexchange" Feb 17 22:23:36 volumio go-librespot[21466]: time="2026-02-17T22:23:36+07:00" level=debug msg="completed challenge" Feb 17 22:23:36 volumio volumio[21450]: info: ------------------------------------------- Feb 17 22:23:36 volumio volumio[21450]: info: ----- Volumio3 ---- Feb 17 22:23:36 volumio volumio[21450]: info: ------------------------------------------- Feb 17 22:23:36 volumio volumio[21450]: info: ----- System startup ---- Feb 17 22:23:36 volumio volumio[21450]: info: ------------------------------------------- Feb 17 22:23:37 volumio go-librespot[21466]: time="2026-02-17T22:23:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 22:23:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:37 volumio volumio-remote-updater[25144]: [2026-02-17 22:23:37] [connect] Successful connection Feb 17 22:23:37 volumio volumio[21450]: info: MYVOLUMIO Environment detected Feb 17 22:23:37 volumio volumio[21450]: info: Plugin folders cleanup Feb 17 22:23:37 volumio volumio[21450]: info: Scanning into folder /volumio/app/plugins/ Feb 17 22:23:37 volumio volumio[21450]: info: Scanning category audio_interface Feb 17 22:23:37 volumio volumio[21450]: info: Scanning category miscellanea Feb 17 22:23:37 volumio volumio[21450]: info: Scanning category music_service Feb 17 22:23:37 volumio volumio[21450]: info: Scanning category plugins.json Feb 17 22:23:37 volumio volumio[21450]: info: Scanning category system_controller Feb 17 22:23:37 volumio volumio[21450]: info: Scanning category user_interface Feb 17 22:23:37 volumio volumio[21450]: info: Scanning into folder /data/plugins/ Feb 17 22:23:37 volumio volumio[21450]: info: Scanning category music_service Feb 17 22:23:37 volumio volumio[21450]: info: Plugin folders cleanup completed Feb 17 22:23:37 volumio volumio[21450]: info: ------------------------------------------- Feb 17 22:23:37 volumio volumio[21450]: info: ----- Core plugins startup ---- Feb 17 22:23:37 volumio volumio[21450]: info: ------------------------------------------- Feb 17 22:23:37 volumio volumio[21450]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 22:23:37 volumio volumio[21450]: info: Adding plugin upnp to MyMusic Plugins Feb 17 22:23:37 volumio volumio[21450]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 22:23:37 volumio volumio[21450]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 22:23:37 volumio volumio[21450]: info: Loading plugins from folder /data/plugins/ Feb 17 22:23:37 volumio volumio[21450]: info: Loading plugin "system"... Feb 17 22:23:37 volumio volumio[21450]: info: Loading plugin "appearance"... Feb 17 22:23:39 volumio volumio[21450]: info: Loading plugin "network"... Feb 17 22:23:39 volumio volumio[21450]: info: Refreshing Cached IP Addresses Feb 17 22:23:39 volumio sudo[21486]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 22:23:39 volumio sudo[21486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:39 volumio sudo[21488]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 22:23:39 volumio volumio[21450]: info: Loading plugin "services"... Feb 17 22:23:39 volumio sudo[21488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:39 volumio sudo[21486]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:39 volumio volumio[21450]: info: Loading plugin "alsa_controller"... Feb 17 22:23:39 volumio sudo[21488]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:39 volumio sudo[21496]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 22:23:39 volumio sudo[21496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:40 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 22:23:40 volumio volumio[21450]: info: Loading plugin "wizard"... Feb 17 22:23:40 volumio volumio[21450]: info: Loading plugin "networkfs"... Feb 17 22:23:40 volumio volumio[21450]: info: Starting Udev Watcher for removable devices Feb 17 22:23:40 volumio volumio[21450]: info: Ignoring mount for partition: boot Feb 17 22:23:40 volumio volumio[21450]: info: Ignoring mount for partition: volumio Feb 17 22:23:40 volumio volumio[21450]: info: Ignoring mount for partition: volumio_data Feb 17 22:23:40 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 22:23:40 volumio volumio[21450]: info: Loading plugin "volumio_command_line_client"... Feb 17 22:23:40 volumio volumio[21450]: info: Loading plugin "upnp"... Feb 17 22:23:40 volumio volumio[21450]: info: [1771341820154] Starting Upmpd Daemon Feb 17 22:23:40 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 22:23:40 volumio volumio[21450]: info: Loading plugin "my_music"... Feb 17 22:23:40 volumio volumio[21450]: info: Loading plugin "mpd"... Feb 17 22:23:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 17 22:23:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:40 volumio go-librespot[21519]: go-librespot daemon starting... Feb 17 22:23:40 volumio go-librespot[21520]: time="2026-02-17T22:23:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:40 volumio go-librespot[21520]: time="2026-02-17T22:23:40+07:00" level=debug msg="app state loaded" Feb 17 22:23:40 volumio go-librespot[21520]: time="2026-02-17T22:23:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:40 volumio volumio[21450]: info: Loading plugin "upnp_browser"... Feb 17 22:23:40 volumio go-librespot[21520]: time="2026-02-17T22:23:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:23:40 volumio go-librespot[21520]: time="2026-02-17T22:23:40+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 17 22:23:40 volumio go-librespot[21520]: time="2026-02-17T22:23:40+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 17 22:23:41 volumio go-librespot[21520]: time="2026-02-17T22:23:41+07:00" level=info msg="zeroconf server listening on port 45701" Feb 17 22:23:41 volumio go-librespot[21520]: time="2026-02-17T22:23:41+07:00" level=debug msg="obtained new client token: AACV4vGjh966L8KEl+pLJHMNrBQmsYV6TvP2TL48w5pziUe3qE2RwtP3gBRUyovkb9KbX2LRRjyaFscTrcAJJ2h/MqDtgEMf6wxfUAmV8RE98nytHecs+PW3CjkmHKfWZ9htcE4LyJp+7YzoIxtOIbrDbDz1iiaX1M6y/GTS4RQJ/2PazwHGlJqhDAALL88CCnj3kEV+s5WlChXzyEPS0acMpxOFKfQCgI/BozTqRBU6E/HYCZ1GF5Y=" Feb 17 22:23:41 volumio go-librespot[21520]: time="2026-02-17T22:23:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:41 volumio go-librespot[21520]: time="2026-02-17T22:23:41+07:00" level=debug msg="completed keyexchange" Feb 17 22:23:41 volumio go-librespot[21520]: time="2026-02-17T22:23:41+07:00" level=debug msg="completed challenge" Feb 17 22:23:41 volumio go-librespot[21520]: time="2026-02-17T22:23:41+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 17 22:23:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:42 volumio sudo[21496]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:43 volumio volumio[21450]: info: Starting UPNP Browser Feb 17 22:23:43 volumio volumio[21450]: info: Loading plugin "alarm-clock"... Feb 17 22:23:44 volumio volumio[21450]: info: Loading plugin "airplay_emulation"... Feb 17 22:23:44 volumio volumio[21450]: info: Starting Shairport Sync Feb 17 22:23:44 volumio volumio[21450]: info: Loading plugin "last_100"... Feb 17 22:23:44 volumio volumio[21450]: info: Loading plugin "webradio"... Feb 17 22:23:44 volumio volumio[21450]: info: Loading plugin "i2s_dacs"... Feb 17 22:23:44 volumio volumio[21450]: info: Loading plugin "volumiodiscovery"... Feb 17 22:23:44 volumio volumio[21450]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 22:23:44 volumio volumio[21450]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:23:44 volumio volumio[21450]: *** WARNING *** For more information see Feb 17 22:23:44 volumio volumio[21450]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 22:23:44 volumio volumio[21450]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:23:44 volumio volumio[21450]: *** WARNING *** For more information see Feb 17 22:23:44 volumio node[21450]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 22:23:44 volumio node[21450]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:23:44 volumio node[21450]: *** WARNING *** For more information see Feb 17 22:23:44 volumio node[21450]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 22:23:44 volumio node[21450]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:23:44 volumio node[21450]: *** WARNING *** For more information see Feb 17 22:23:44 volumio volumio[21450]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 22:23:44 volumio volumio[21450]: info: Discovery: Started advertising with name: Volumio Feb 17 22:23:44 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 22:23:44 volumio volumio[21450]: info: Loading plugin "spop"... Feb 17 22:23:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 17 22:23:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:44 volumio go-librespot[21530]: go-librespot daemon starting... Feb 17 22:23:44 volumio go-librespot[21531]: time="2026-02-17T22:23:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:44 volumio go-librespot[21531]: time="2026-02-17T22:23:44+07:00" level=debug msg="app state loaded" Feb 17 22:23:44 volumio go-librespot[21531]: time="2026-02-17T22:23:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:45 volumio go-librespot[21531]: time="2026-02-17T22:23:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:23:45 volumio go-librespot[21531]: time="2026-02-17T22:23:45+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 17 22:23:45 volumio go-librespot[21531]: time="2026-02-17T22:23:45+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 17 22:23:45 volumio go-librespot[21531]: time="2026-02-17T22:23:45+07:00" level=info msg="zeroconf server listening on port 37389" Feb 17 22:23:45 volumio go-librespot[21531]: time="2026-02-17T22:23:45+07:00" level=debug msg="obtained new client token: AAAYvX+2K6ae+z9kA0/xolY61G8O3DUyBsGd8mgsigM8HG74ZU+i9MfUvxXe9usEBjt2MOnUhq55ZyFELDuYD6JIrcO6+AU8w5J+FbJM/osfOHjMb/RRB6KO34j11tXCAPINnw/QtrZPCrPR+cydt/V5eAZbxcDbLN5xWlYvECBl9GUIyndndouoV7Z07c0g7cOhOgvXPAEzXO0TWcA41K+xQQoq50ByZuxzMnK01PwZWakSm6Vxe2yclA==" Feb 17 22:23:45 volumio go-librespot[21531]: time="2026-02-17T22:23:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:45 volumio go-librespot[21531]: time="2026-02-17T22:23:45+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 17 22:23:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:46 volumio volumio[21450]: info: Loading plugin "ytcr"... Feb 17 22:23:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 17 22:23:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:48 volumio go-librespot[21539]: go-librespot daemon starting... Feb 17 22:23:48 volumio go-librespot[21540]: time="2026-02-17T22:23:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:48 volumio go-librespot[21540]: time="2026-02-17T22:23:48+07:00" level=debug msg="app state loaded" Feb 17 22:23:48 volumio go-librespot[21540]: time="2026-02-17T22:23:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:48 volumio volumio[21450]: info: Loading plugin "ytmusic"... Feb 17 22:23:49 volumio go-librespot[21540]: time="2026-02-17T22:23:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:23:49 volumio go-librespot[21540]: time="2026-02-17T22:23:49+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 17 22:23:49 volumio go-librespot[21540]: time="2026-02-17T22:23:49+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 17 22:23:49 volumio go-librespot[21540]: time="2026-02-17T22:23:49+07:00" level=info msg="zeroconf server listening on port 35501" Feb 17 22:23:49 volumio go-librespot[21540]: time="2026-02-17T22:23:49+07:00" level=debug msg="obtained new client token: AABs7pzVHAM0LAy4mIHiyYe7UGJHU+M9sB/zULBdlLEYqezymMDnkDFx6ocVEEAXZ0av+NI2Qx0LgZk2IKK/v/cNk5zknFgDesmDuYcyFdTttvVCjgXCWaijunYy3A5jAU8XSmJ1X8/GGOIaOwgRGGJuQgAsXspz32R0c1oUJ6gO+2gFE39VBG4P++PR5ctsUGSZgQ1I+XwAnOl3xHR/OeNaVflbj4V9RhTKg5+4kCI+E5KtxXNSHhqsYw==" Feb 17 22:23:49 volumio go-librespot[21540]: time="2026-02-17T22:23:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:49 volumio volumio-remote-updater[25144]: [2026-02-17 22:23:49] [connect] Successful connection Feb 17 22:23:49 volumio go-librespot[21540]: time="2026-02-17T22:23:49+07:00" level=debug msg="completed keyexchange" Feb 17 22:23:49 volumio go-librespot[21540]: time="2026-02-17T22:23:49+07:00" level=debug msg="completed challenge" Feb 17 22:23:50 volumio go-librespot[21540]: time="2026-02-17T22:23:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 22:23:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:50 volumio volumio[21450]: info: Loading plugin "outputs"... Feb 17 22:23:50 volumio volumio[21450]: info: Loading plugin "albumart"... Feb 17 22:23:50 volumio volumio[21450]: info: Plugin example_plugin is not enabled Feb 17 22:23:50 volumio volumio[21450]: info: Loading plugin "inputs"... Feb 17 22:23:50 volumio volumio[21450]: info: Loading plugin "updater_comm"... Feb 17 22:23:50 volumio volumio[21450]: info: Plugin mpdemulation is not enabled Feb 17 22:23:50 volumio volumio[21450]: info: Loading plugin "rest_api"... Feb 17 22:23:50 volumio volumio[21450]: info: Loading plugin "websocket"... Feb 17 22:23:50 volumio volumio[21450]: info: Starting Socket.io Server version 1.7.4 Feb 17 22:23:50 volumio volumio[21450]: info: Loading plugin "RoonBridge"... Feb 17 22:23:50 volumio volumio[21450]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 22:23:50 volumio volumio[21450]: info: Loading i18n strings for locale en Feb 17 22:23:51 volumio volumio[21450]: Updating browse sources language Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::initPlayerControls Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 22:23:51 volumio volumio[21450]: Express server listening on port 3000 Feb 17 22:23:51 volumio volumio[21562]: Forking 3 albumart workers Feb 17 22:23:51 volumio volumio[21450]: [Metrics] WebUI: 16s 5.34ms Feb 17 22:23:51 volumio volumio[21450]: info: CoreStateMachine::resetVolumioState Feb 17 22:23:51 volumio volumio[21450]: info: CoreStateMachine::getcurrentVolume Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 22:23:51 volumio sudo[21605]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 22:23:51 volumio sudo[21605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:51 volumio sudo[21596]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 22:23:51 volumio sudo[21596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:51 volumio sudo[21605]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:51 volumio sudo[21596]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:51 volumio volumio[21450]: info: Volumio Network Manager: Network status updated: 1 Feb 17 22:23:51 volumio volumio[21450]: info: VolumeController:: Volume=100 Mute =false Feb 17 22:23:51 volumio volumio[21450]: info: CoreStateMachine::pushState Feb 17 22:23:51 volumio volumio[21450]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::volumioPushState Feb 17 22:23:51 volumio volumio[21450]: info: CoreStateMachine::updateTrackBlock Feb 17 22:23:51 volumio volumio[21450]: info: CorePlayQueue::getTrackBlock Feb 17 22:23:51 volumio volumio[21450]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 22:23:52 volumio volumio-remote-updater[25144]: [2026-02-17 22:23:52] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771341829 101 Feb 17 22:23:52 volumio volumio[21450]: 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 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:52 volumio volumio[21450]: info: Reloading queue from file Feb 17 22:23:52 volumio volumio[21450]: info: CoreStateMachine::setRepeat null single undefined Feb 17 22:23:52 volumio volumio[21450]: info: CoreStateMachine::pushState Feb 17 22:23:52 volumio volumio[21450]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::volumioPushState Feb 17 22:23:52 volumio volumio[21450]: info: CoreStateMachine::setRandom null Feb 17 22:23:52 volumio volumio[21450]: info: CoreStateMachine::pushState Feb 17 22:23:52 volumio volumio[21450]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::volumioPushState Feb 17 22:23:52 volumio volumio[21450]: info: Setting Device type: Raspberry PI Feb 17 22:23:52 volumio volumio[21450]: info: Completed loading Core Plugins Feb 17 22:23:52 volumio volumio[21450]: info: Preparing to generate the ALSA configuration file Feb 17 22:23:52 volumio volumio[21450]: info: VolumeController:: Volume=100 Mute =false Feb 17 22:23:52 volumio volumio[21450]: info: CoreStateMachine::pushState Feb 17 22:23:52 volumio volumio[21450]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::volumioPushState Feb 17 22:23:52 volumio volumio[21450]: info: Asound.conf file unchanged, so no further update is needed Feb 17 22:23:52 volumio volumio[21450]: info: Output device has changed, restarting MPD Feb 17 22:23:52 volumio sudo[21624]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 22:23:52 volumio sudo[21624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:52 volumio volumio[21450]: info: Output device has changed, restarting Shairport Sync Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:52 volumio sudo[21626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 22:23:52 volumio sudo[21626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:52 volumio sudo[21626]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:52 volumio sudo[21624]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:52 volumio sudo[21629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 22:23:52 volumio sudo[21629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:52 volumio volumio[21450]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 22:23:52 volumio volumio[21450]: info: ___________ START PLUGINS ___________ Feb 17 22:23:52 volumio volumio[21450]: info: ControllerMpd::onStart: Initializing MPD Feb 17 22:23:52 volumio volumio[21450]: info: Creating MPD Configuration file Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:23:52 volumio volumio[21450]: info: [1771341832841] CoreMusicLibrary::Adding element Media Servers Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:52 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 22:23:52 volumio sudo[21637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 22:23:52 volumio sudo[21637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:52 volumio sudo[21637]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:52 volumio volumio[21450]: info: UPNP Browser: Client initialized successfully Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:52 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:52 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 22:23:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 22:23:53 volumio systemd[1]: mpd.service: Consumed 7.232s CPU time. Feb 17 22:23:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 22:23:53 volumio sudo[21639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 22:23:53 volumio sudo[21639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 22:23:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 22:23:53 volumio volumio[21450]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 22:23:53 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:53 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:53 volumio volumio[21450]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 22:23:53 volumio volumio[21450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:23:53 volumio volumio[21450]: info: [1771341833103] CoreMusicLibrary::Adding element Last_100 Feb 17 22:23:53 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 22:23:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 22:23:53 volumio volumio[21450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:23:53 volumio volumio[21450]: info: [1771341833182] CoreMusicLibrary::Adding element Webradio Feb 17 22:23:53 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 17 22:23:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:53 volumio go-librespot[21652]: go-librespot daemon starting... Feb 17 22:23:53 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 22:23:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 22:23:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 22:23:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 22:23:53 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 22:23:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 22:23:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 22:23:53 volumio volumio[21450]: info: Initializing BBC Radios Feb 17 22:23:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 22:23:53 volumio go-librespot[21653]: time="2026-02-17T22:23:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:53 volumio go-librespot[21653]: time="2026-02-17T22:23:53+07:00" level=debug msg="app state loaded" Feb 17 22:23:53 volumio go-librespot[21653]: time="2026-02-17T22:23:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:53 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 22:23:53 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:53 volumio volumio[21450]: info: Creating Spotify config file Feb 17 22:23:53 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:53 volumio sudo[21660]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 22:23:53 volumio sudo[21660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 22:23:53 volumio sudo[21660]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:53 volumio go-librespot[21653]: time="2026-02-17T22:23:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:23:53 volumio go-librespot[21653]: time="2026-02-17T22:23:53+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 17 22:23:53 volumio go-librespot[21653]: time="2026-02-17T22:23:53+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 17 22:23:54 volumio go-librespot[21653]: time="2026-02-17T22:23:54+07:00" level=info msg="zeroconf server listening on port 46549" Feb 17 22:23:54 volumio go-librespot[21653]: time="2026-02-17T22:23:54+07:00" level=debug msg="obtained new client token: AABHsfGM3lazEtblUA39Pz7mDCGEKR1oNHruIP3wmFi6QBasiC9gydFvVIAaQnzAN6mVd4Xa+dHLaI0ZAmnU5A5gie6HVpIlMIwLydWGdOj6NS0fXCrJtTXNFsusbq9l2Y+Vt/Odz2/d79dT544lMGFy399WfesTklyVl/F/PXl4FodGQb/28VOs24vKuwxlvcFnCWdDfxia19UXavmde8WXWu8CthzCgtQ1G/JWPmvhKkoqWaXHoErbAg==" Feb 17 22:23:54 volumio go-librespot[21653]: time="2026-02-17T22:23:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:54 volumio volumio[21576]: Starting albumart workers Feb 17 22:23:54 volumio go-librespot[21653]: time="2026-02-17T22:23:54+07:00" level=debug msg="completed keyexchange" Feb 17 22:23:54 volumio go-librespot[21653]: time="2026-02-17T22:23:54+07:00" level=debug msg="completed challenge" Feb 17 22:23:54 volumio go-librespot[21653]: time="2026-02-17T22:23:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 22:23:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:54 volumio volumio[21450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:23:54 volumio volumio[21450]: info: [1771341834819] CoreMusicLibrary::Adding element YouTube Music Feb 17 22:23:54 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:54 volumio volumio[21450]: Cannot find translation for source YouTube Music Feb 17 22:23:54 volumio volumio[21450]: info: Volumio Calling Home Feb 17 22:23:54 volumio sudo[21679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 22:23:54 volumio sudo[21679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:55 volumio volumio[21573]: Starting albumart workers Feb 17 22:23:55 volumio sudo[21679]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:55 volumio volumio[21577]: Starting albumart workers Feb 17 22:23:55 volumio volumio[21450]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 22:23:55 volumio volumio[21450]: info: Discovery: Found device Volumio Feb 17 22:23:55 volumio volumio[21450]: info: CoreCommandRouter::volumioGetState Feb 17 22:23:55 volumio volumio[21450]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:55 volumio volumio[21450]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 22:23:55 volumio volumio[21450]: info: Discovery: Found device Volumio Feb 17 22:23:55 volumio volumio[21450]: info: CoreCommandRouter::volumioGetState Feb 17 22:23:55 volumio volumio[21450]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:55 volumio volumio[21450]: info: MPD Permissions set Feb 17 22:23:55 volumio volumio[21450]: info: MPD Permissions set Feb 17 22:23:55 volumio volumio[21450]: info: Upmpdcli Daemon Started Feb 17 22:23:55 volumio volumio[21450]: info: Volumio called home Feb 17 22:23:55 volumio volumio[21450]: info: Spotify config file written Feb 17 22:23:56 volumio sudo[21685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 22:23:56 volumio sudo[21685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:23:56 volumio go-librespot[21687]: go-librespot daemon starting... Feb 17 22:23:56 volumio volumio[21450]: 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 17 22:23:56 volumio sudo[21685]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio go-librespot[21688]: time="2026-02-17T22:23:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:23:56 volumio go-librespot[21688]: time="2026-02-17T22:23:56+07:00" level=debug msg="app state loaded" Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio go-librespot[21688]: time="2026-02-17T22:23:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:23:56 volumio volumio[21450]: info: No need to fix Spotify hosts Feb 17 22:23:57 volumio go-librespot[21688]: time="2026-02-17T22:23: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:23:57 volumio go-librespot[21688]: time="2026-02-17T22:23:57+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 17 22:23:57 volumio go-librespot[21688]: time="2026-02-17T22:23:57+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 17 22:23:57 volumio go-librespot[21688]: time="2026-02-17T22:23:57+07:00" level=info msg="zeroconf server listening on port 38567" Feb 17 22:23:57 volumio go-librespot[21688]: time="2026-02-17T22:23:57+07:00" level=debug msg="obtained new client token: AAAOtVhF0IXOu2TaDvJoNCJfzq+D0jnbg0yZ6I5HR2cZw50iQ7l1tGsQeUDulPA6fOawDvi5KgNsNO7dgyq2MdGruL6Ms8z+w0/7X5U+Ek4NT8nt3g0llClXePZGI4rIgrMLI0e8czWXgH8jvcYWoAlYtXUreJOwiCg675Iw1AamBCt8srNod1Ju0rYHi1ufKTFUqugrsXVH4ChMqU7JRykewxZQaHqWELX/fYbqt6UfC7dB5aUTUCdxXQ==" Feb 17 22:23:57 volumio go-librespot[21688]: time="2026-02-17T22:23:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:23:57 volumio go-librespot[21688]: time="2026-02-17T22:23:57+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 17 22:23:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:23:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:23:57 volumio volumio[21450]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 22:23:57 volumio volumio[21450]: SPOTIFY: BQBOAWWfBL5EyRYR7tbRFN197Tt7FHD_Hg2FREpRrR8Z3YykngiDe5EbzwXOt_en7QLWwBw5xR3kJGnGEUUShf2GZpnJCQfaalyn4beVy_8H4ZdT59dTODH5-j-X0J7DjHbz8tZV2fbsBMwn0gzSgfD0QJM8i557DgZoOMEo4raYfczP9hx7qOPxqxBONNjiPC80bukdAJe2yNA3nWU7mtPA_NuvjbwQ3F8J3whAnCuqfIlNBINFg3q0rdSgvO5AlMQ8_nTd7RSNiSCoXBl8_fKhPkqkvwNW5ogKshqprWZoYrL9P3tYCDwv Feb 17 22:23:57 volumio volumio[21450]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 22:23:57 volumio volumio[21450]: info: New Spotify access token = BQBOAWWfBL5EyRYR7tbRFN197Tt7FHD_Hg2FREpRrR8Z3YykngiDe5EbzwXOt_en7QLWwBw5xR3kJGnGEUUShf2GZpnJCQfaalyn4beVy_8H4ZdT59dTODH5-j-X0J7DjHbz8tZV2fbsBMwn0gzSgfD0QJM8i557DgZoOMEo4raYfczP9hx7qOPxqxBONNjiPC80bukdAJe2yNA3nWU7mtPA_NuvjbwQ3F8J3whAnCuqfIlNBINFg3q0rdSgvO5AlMQ8_nTd7RSNiSCoXBl8_fKhPkqkvwNW5ogKshqprWZoYrL9P3tYCDwv Feb 17 22:23:57 volumio volumio[21450]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 22:23:57 volumio volumio[21450]: info: Starting Shairport Sync Feb 17 22:23:57 volumio volumio[21450]: info: Starting Shairport Sync Feb 17 22:23:57 volumio volumio[21450]: info: Starting Shairport Sync Feb 17 22:23:57 volumio sudo[21724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 22:23:57 volumio sudo[21724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:57 volumio sudo[21726]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 22:23:57 volumio sudo[21728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 22:23:57 volumio sudo[21728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:57 volumio sudo[21726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:23:57 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 22:23:57 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 22:23:57 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 22:23:57 volumio systemd[1]: shairport-sync.service: Consumed 2.271s CPU time. Feb 17 22:23:58 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 22:23:58 volumio sudo[21724]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:58 volumio sudo[21726]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:58 volumio sudo[21728]: pam_unix(sudo:session): session closed for user root Feb 17 22:23:58 volumio volumio[21450]: info: CoreCommandRouter::volumioGetState Feb 17 22:23:58 volumio volumio[21450]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:58 volumio volumio[21450]: info: Shairport-Sync Started Feb 17 22:23:58 volumio volumio[21450]: Error adding Membership: Error: addMembership EINVAL Feb 17 22:23:58 volumio volumio[21450]: info: Shairport-Sync Started Feb 17 22:23:58 volumio volumio[21450]: info: Shairport-Sync Started Feb 17 22:23:58 volumio volumio[21450]: 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 17 22:23:58 volumio volumio[21450]: info: Spotify Successfully logged in Feb 17 22:23:58 volumio volumio[21450]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:23:58 volumio volumio[21450]: info: [1771341838453] CoreMusicLibrary::Adding element Spotify Feb 17 22:23:58 volumio volumio[21450]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:23:58 volumio volumio[21450]: Cannot find translation for source YouTube Music Feb 17 22:23:58 volumio volumio[21450]: Cannot find translation for source Spotify Feb 17 22:23:58 volumio volumio[21450]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 22:23:59 volumio volumio[21450]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 22:23:59 volumio volumio[21450]: info: VolumeController:: Volume=100 Mute =false Feb 17 22:23:59 volumio volumio[21450]: info: CoreCommandRouter::volumioGetState Feb 17 22:23:59 volumio volumio[21450]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:59 volumio volumio[21450]: info: CoreStateMachine::pushState Feb 17 22:23:59 volumio volumio[21450]: info: CorePlayQueue::getTrack 0 Feb 17 22:23:59 volumio volumio[21450]: info: CoreCommandRouter::volumioPushState Feb 17 22:24:00 volumio volumio[21450]: info: go-librespot daemon successfully initialized Feb 17 22:24:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 17 22:24:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:00 volumio go-librespot[21765]: go-librespot daemon starting... Feb 17 22:24:00 volumio go-librespot[21766]: time="2026-02-17T22:24:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:00 volumio go-librespot[21766]: time="2026-02-17T22:24:00+07:00" level=debug msg="app state loaded" Feb 17 22:24:00 volumio go-librespot[21766]: time="2026-02-17T22:24:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:00 volumio mpd[21677]: 2026-02-17T22:24:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 22:24:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 22:24:00 volumio sudo[21639]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:00 volumio sudo[21629]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:00 volumio volumio[21450]: error: MPD error: The expression evaluated to a falsy value: Feb 17 22:24:00 volumio volumio[21450]: assert.ok(self.idling) Feb 17 22:24:00 volumio volumio[21450]: error: The expression evaluated to a falsy value: Feb 17 22:24:00 volumio volumio[21450]: assert.ok(self.idling) Feb 17 22:24:00 volumio volumio[21450]: error: updateQueue error: null Feb 17 22:24:00 volumio volumio[21450]: info: MPD running with PID21677 Feb 17 22:24:00 volumio volumio[21450]: ,establishing connection Feb 17 22:24:01 volumio volumio[21450]: info: Completed starting Core Plugins Feb 17 22:24:01 volumio volumio[21450]: info: ------------------------------------------- Feb 17 22:24:01 volumio volumio[21450]: info: ----- MyVolumio plugins startup ---- Feb 17 22:24:01 volumio volumio[21450]: info: ------------------------------------------- Feb 17 22:24:01 volumio volumio[21450]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 22:24:01 volumio volumio[21450]: error: updateQueue error: null Feb 17 22:24:01 volumio go-librespot[21766]: time="2026-02-17T22:24:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:24:01 volumio go-librespot[21766]: time="2026-02-17T22:24:01+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 17 22:24:01 volumio go-librespot[21766]: time="2026-02-17T22:24:01+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 17 22:24:01 volumio go-librespot[21766]: time="2026-02-17T22:24:01+07:00" level=info msg="zeroconf server listening on port 39963" Feb 17 22:24:01 volumio go-librespot[21766]: time="2026-02-17T22:24:01+07:00" level=debug msg="obtained new client token: AADI9iiKdcHuW/msXaH7GrEGXTQnZmSqn/AMtNrvIOQEHRk9QiWr1n9ADe8gyAQg1Hq30PmsqLrA2oFpDDT+y7nzMyp/PNrTWnVQUnoYfzT3kcEK1Bhpjfa0Sj0FmwPlria6TMm/374kEhoF1g6bf+A2mNQTRA7aY78dHsqu+ubQlnz2H1rGg7I271hrT2z9zgEE2Pb7iXlOi8xQTGXvWsHE0Fel1Nhv39xf4Cbm5wfePkBUElnK6vYAKg==" Feb 17 22:24:01 volumio go-librespot[21766]: time="2026-02-17T22:24:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:01 volumio go-librespot[21766]: time="2026-02-17T22:24:01+07:00" level=debug msg="completed keyexchange" Feb 17 22:24:01 volumio go-librespot[21766]: time="2026-02-17T22:24:01+07:00" level=debug msg="completed challenge" Feb 17 22:24:01 volumio go-librespot[21766]: time="2026-02-17T22:24: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 17 22:24:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:03 volumio volumio[21450]: info: Initializing connection to go-librespot Websocket Feb 17 22:24:03 volumio volumio[21450]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 22:24:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 17 22:24:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:04 volumio go-librespot[21778]: go-librespot daemon starting... Feb 17 22:24:04 volumio go-librespot[21779]: time="2026-02-17T22:24:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:04 volumio go-librespot[21779]: time="2026-02-17T22:24:04+07:00" level=debug msg="app state loaded" Feb 17 22:24:04 volumio go-librespot[21779]: time="2026-02-17T22:24:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:05 volumio go-librespot[21779]: time="2026-02-17T22:24:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 22:24:05 volumio go-librespot[21779]: time="2026-02-17T22:24:05+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 17 22:24:05 volumio go-librespot[21779]: time="2026-02-17T22:24:05+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 17 22:24:05 volumio go-librespot[21779]: time="2026-02-17T22:24:05+07:00" level=info msg="zeroconf server listening on port 39155" Feb 17 22:24:05 volumio go-librespot[21779]: time="2026-02-17T22:24:05+07:00" level=debug msg="obtained new client token: AADkqC6Z31FUu6pyKobSWkRnxExHJTfm4sRhrIpb3wXVyLUhYfbPhRyQhUG4P4/8lTRNFsc0ry0zicashQ3FpRrNinr7vV+aceNxPPo0IqANMaRoudon23jCn4KhtfAKE1iOl/ho7sDLQZuNZDxdlUf9zVqNfxtH9c6WyJ6W0g1jizbQ8LqMtzy1/qL9IRTXm8uBQvSNi7jVsmSdYdNQcZSif7D/ZjhCA7uXWd3bojmsI1uDklYQ7fkcLw==" Feb 17 22:24:05 volumio volumio[21450]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 22:24:05 volumio go-librespot[21779]: time="2026-02-17T22:24:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:06 volumio volumio[21450]: info: Initializing connection to go-librespot Websocket Feb 17 22:24:06 volumio go-librespot[21779]: time="2026-02-17T22:24:06+07:00" level=debug msg="new websocket client" Feb 17 22:24:06 volumio volumio[21450]: info: Connection to go-librespot Websocket established Feb 17 22:24:06 volumio go-librespot[21779]: time="2026-02-17T22:24:06+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: read tcp 192.168.1.23:39578->104.199.241.202:4070: read: connection reset by peer" Feb 17 22:24:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:06 volumio volumio[21450]: info: Connection to go-librespot Websocket closed Feb 17 22:24:09 volumio volumio[21450]: info: Getting Spotify volume Feb 17 22:24:09 volumio volumio[21450]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 22:24:09 volumio volumio[21450]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 22:24:09 volumio volumio[21450]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 22:24:09 volumio volumio[21450]: errno: -111, Feb 17 22:24:09 volumio volumio[21450]: code: 'ECONNREFUSED', Feb 17 22:24:09 volumio volumio[21450]: syscall: 'connect', Feb 17 22:24:09 volumio volumio[21450]: address: '127.0.0.1', Feb 17 22:24:09 volumio volumio[21450]: port: 9879, Feb 17 22:24:09 volumio volumio[21450]: response: undefined Feb 17 22:24:09 volumio volumio[21450]: } Feb 17 22:24:09 volumio volumio[21450]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 22:24:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 17 22:24:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:09 volumio go-librespot[21799]: go-librespot daemon starting... Feb 17 22:24:09 volumio go-librespot[21801]: time="2026-02-17T22:24:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:09 volumio go-librespot[21801]: time="2026-02-17T22:24:09+07:00" level=debug msg="app state loaded" Feb 17 22:24:09 volumio go-librespot[21801]: time="2026-02-17T22:24:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:10 volumio go-librespot[21801]: time="2026-02-17T22:24:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:24:10 volumio go-librespot[21801]: time="2026-02-17T22:24:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 22:24:10 volumio go-librespot[21801]: time="2026-02-17T22:24:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 22:24:10 volumio go-librespot[21801]: time="2026-02-17T22:24:10+07:00" level=info msg="zeroconf server listening on port 33101" Feb 17 22:24:10 volumio go-librespot[21801]: time="2026-02-17T22:24:10+07:00" level=debug msg="obtained new client token: AADND5jJx1g126NPxR+X/4s91b9jbE+H4aPCHaMaufucZJZUI3W1u+lug0xpXo7CFhe9VPGknN8qS7TRUhv4L1pHla0RDcteCbQsUpT3T5wFHj4bZCRM4t1rBe9DzVnVO9KTk6gaDn6NvyefNV3dj2KUHXKckYukv9ic+J3z1EwyGdX6gh0CxMzko3M1C3tZhWzx0z268VnKqJd8URyRQXtX3qBGJzbgR7exAQbytOyxfmXxYwVuxrZiNg==" Feb 17 22:24:10 volumio go-librespot[21801]: time="2026-02-17T22:24:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:10 volumio go-librespot[21801]: time="2026-02-17T22:24:10+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 17 22:24:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:10 volumio sudo[21824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 22:23' Feb 17 22:24:10 volumio sudo[21824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:11 volumio sudo[21824]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:11 volumio volumio-remote-updater[25144]: [2026-02-17 22:24:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 22:24:11 volumio volumio-remote-updater[25144]: [2026-02-17 22:24:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 22:24:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 22:24:11 volumio systemd[1]: volumio.service: Consumed 49.363s CPU time. Feb 17 22:24:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 22:24:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 22:24:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20984. Feb 17 22:24:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 22:24:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 22:24:11 volumio systemd[1]: volumio.service: Consumed 49.363s CPU time. Feb 17 22:24:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 22:24:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 22:24:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 17 22:24:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:13 volumio go-librespot[21854]: go-librespot daemon starting... Feb 17 22:24:13 volumio go-librespot[21855]: time="2026-02-17T22:24:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:13 volumio go-librespot[21855]: time="2026-02-17T22:24:13+07:00" level=debug msg="app state loaded" Feb 17 22:24:13 volumio go-librespot[21855]: time="2026-02-17T22:24:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:14 volumio go-librespot[21855]: time="2026-02-17T22:24: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-gew4.spotify.com:80]" Feb 17 22:24:14 volumio go-librespot[21855]: time="2026-02-17T22:24:14+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 17 22:24:14 volumio go-librespot[21855]: time="2026-02-17T22:24:14+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 17 22:24:14 volumio go-librespot[21855]: time="2026-02-17T22:24:14+07:00" level=info msg="zeroconf server listening on port 40073" Feb 17 22:24:14 volumio go-librespot[21855]: time="2026-02-17T22:24:14+07:00" level=debug msg="obtained new client token: AAC8nmv5c35bHu4bNXyFYJaZOLJkFGngB4b4sBmqPmO6esSo/c77oVZ+9pjJyKVa40AkAe2R8FFgQAMCbIqaAedYWaYzej+ft1Oi48kNkwvCtvdHbx6hwa+07pKVB85FWpfvxFX2MfZfOSWNtZ0nTae23yKztgRsVOLpMugCm5hiI89gn2AJx9g3cosfak7jGrM7BvgnL/HvNZhdEQMWaWx5PUSuxeSgZyIonTc8ZLBl3nDbTtcMJm8WIA==" Feb 17 22:24:14 volumio go-librespot[21855]: time="2026-02-17T22:24:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:14 volumio go-librespot[21855]: time="2026-02-17T22:24:14+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 17 22:24:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:15 volumio volumio[21839]: info: ------------------------------------------- Feb 17 22:24:15 volumio volumio[21839]: info: ----- Volumio3 ---- Feb 17 22:24:15 volumio volumio[21839]: info: ------------------------------------------- Feb 17 22:24:15 volumio volumio[21839]: info: ----- System startup ---- Feb 17 22:24:15 volumio volumio[21839]: info: ------------------------------------------- Feb 17 22:24:16 volumio volumio-remote-updater[25144]: [2026-02-17 22:24:16] [connect] Successful connection Feb 17 22:24:16 volumio volumio[21839]: info: MYVOLUMIO Environment detected Feb 17 22:24:16 volumio volumio[21839]: info: Plugin folders cleanup Feb 17 22:24:16 volumio volumio[21839]: info: Scanning into folder /volumio/app/plugins/ Feb 17 22:24:16 volumio volumio[21839]: info: Scanning category audio_interface Feb 17 22:24:16 volumio volumio[21839]: info: Scanning category miscellanea Feb 17 22:24:16 volumio volumio[21839]: info: Scanning category music_service Feb 17 22:24:16 volumio volumio[21839]: info: Scanning category plugins.json Feb 17 22:24:16 volumio volumio[21839]: info: Scanning category system_controller Feb 17 22:24:16 volumio volumio[21839]: info: Scanning category user_interface Feb 17 22:24:16 volumio volumio[21839]: info: Scanning into folder /data/plugins/ Feb 17 22:24:16 volumio volumio[21839]: info: Scanning category music_service Feb 17 22:24:16 volumio volumio[21839]: info: Plugin folders cleanup completed Feb 17 22:24:16 volumio volumio[21839]: info: ------------------------------------------- Feb 17 22:24:16 volumio volumio[21839]: info: ----- Core plugins startup ---- Feb 17 22:24:16 volumio volumio[21839]: info: ------------------------------------------- Feb 17 22:24:16 volumio volumio[21839]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 22:24:16 volumio volumio[21839]: info: Adding plugin upnp to MyMusic Plugins Feb 17 22:24:16 volumio volumio[21839]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 22:24:16 volumio volumio[21839]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 22:24:16 volumio volumio[21839]: info: Loading plugins from folder /data/plugins/ Feb 17 22:24:16 volumio volumio[21839]: info: Loading plugin "system"... Feb 17 22:24:16 volumio volumio[21839]: info: Loading plugin "appearance"... Feb 17 22:24:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 17 22:24:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:18 volumio go-librespot[21875]: go-librespot daemon starting... Feb 17 22:24:18 volumio go-librespot[21876]: time="2026-02-17T22:24:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:18 volumio go-librespot[21876]: time="2026-02-17T22:24:18+07:00" level=debug msg="app state loaded" Feb 17 22:24:18 volumio go-librespot[21876]: time="2026-02-17T22:24:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:18 volumio go-librespot[21876]: time="2026-02-17T22:24: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 17 22:24:18 volumio go-librespot[21876]: time="2026-02-17T22:24: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 17 22:24:18 volumio go-librespot[21876]: time="2026-02-17T22:24: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 17 22:24:18 volumio go-librespot[21876]: time="2026-02-17T22:24:18+07:00" level=info msg="zeroconf server listening on port 42019" Feb 17 22:24:18 volumio volumio[21839]: info: Loading plugin "network"... Feb 17 22:24:18 volumio volumio[21839]: info: Refreshing Cached IP Addresses Feb 17 22:24:18 volumio sudo[21884]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 22:24:18 volumio sudo[21884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:18 volumio sudo[21886]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 22:24:18 volumio sudo[21886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:18 volumio sudo[21884]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:18 volumio volumio[21839]: info: Loading plugin "services"... Feb 17 22:24:18 volumio sudo[21886]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:18 volumio volumio[21839]: info: Loading plugin "alsa_controller"... Feb 17 22:24:18 volumio sudo[21895]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 22:24:18 volumio sudo[21895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:19 volumio go-librespot[21876]: time="2026-02-17T22:24:19+07:00" level=debug msg="obtained new client token: AAAtw/1E+Ft5acHr3gLxGLMAUchS2kClPBAruPzzF9seNTWsFELtLnZh9HKzC1/SVe8HlzxO8rgAPd2I54dsoGRxmc01QMh3ZLW3LIK0RJBn75nbwzPWcr3/Mo/EiYHEHsVzYvfso7oAk8zcVC2Xbrqz556EaB1cDItUXp4eQ6avfgWbzmCq8VbT0xy8DXzBOaelKchtiv8hEBE38k3F+BjHO5Ujj8j6KkCjQTHCc3EMgR4mvM47h0FHPA==" Feb 17 22:24:19 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 22:24:19 volumio volumio[21839]: info: Loading plugin "wizard"... Feb 17 22:24:19 volumio go-librespot[21876]: time="2026-02-17T22:24:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:19 volumio volumio[21839]: info: Loading plugin "networkfs"... Feb 17 22:24:19 volumio volumio[21839]: info: Starting Udev Watcher for removable devices Feb 17 22:24:19 volumio go-librespot[21876]: time="2026-02-17T22:24:19+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 17 22:24:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:19 volumio volumio[21839]: info: Ignoring mount for partition: boot Feb 17 22:24:19 volumio volumio[21839]: info: Ignoring mount for partition: volumio Feb 17 22:24:19 volumio volumio[21839]: info: Ignoring mount for partition: volumio_data Feb 17 22:24:19 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 22:24:19 volumio volumio[21839]: info: Loading plugin "volumio_command_line_client"... Feb 17 22:24:19 volumio volumio[21839]: info: Loading plugin "upnp"... Feb 17 22:24:19 volumio volumio[21839]: info: [1771341859249] Starting Upmpd Daemon Feb 17 22:24:19 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 22:24:19 volumio volumio[21839]: info: Loading plugin "my_music"... Feb 17 22:24:19 volumio volumio[21839]: info: Loading plugin "mpd"... Feb 17 22:24:19 volumio volumio[21839]: info: Loading plugin "upnp_browser"... Feb 17 22:24:21 volumio sudo[21895]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 17 22:24:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:22 volumio go-librespot[21918]: go-librespot daemon starting... Feb 17 22:24:22 volumio go-librespot[21919]: time="2026-02-17T22:24:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:22 volumio go-librespot[21919]: time="2026-02-17T22:24:22+07:00" level=debug msg="app state loaded" Feb 17 22:24:22 volumio go-librespot[21919]: time="2026-02-17T22:24:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:22 volumio volumio[21839]: info: Starting UPNP Browser Feb 17 22:24:22 volumio volumio[21839]: info: Loading plugin "alarm-clock"... Feb 17 22:24:22 volumio go-librespot[21919]: time="2026-02-17T22:24: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 17 22:24:22 volumio go-librespot[21919]: time="2026-02-17T22:24: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 17 22:24:22 volumio go-librespot[21919]: time="2026-02-17T22:24: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 17 22:24:22 volumio go-librespot[21919]: time="2026-02-17T22:24:22+07:00" level=info msg="zeroconf server listening on port 46729" Feb 17 22:24:23 volumio go-librespot[21919]: time="2026-02-17T22:24:23+07:00" level=debug msg="obtained new client token: AACwVghLGC/P6C5uvRzU4IciEW2SAmKF+3MMYDTO+OPe0qHVla2KmVhmBJAeu3l0H32OyMFBQtDN7VwbZf+PPU+KPE45169IiVfQ+Wq8sAU63/+GBxzSn5QtMfxz2PVpXmHxFf9Xtlal0yTjAB82LZnHwN0gsG7+s04s6Io6ylj3vY1rTqjNgTnvdaYfdMIB3aJtKVFR6hjEhxujloJlnDwpryXwh2XIRcyrP39l03y2TOiLCdsXS9Y=" Feb 17 22:24:23 volumio volumio[21839]: info: Loading plugin "airplay_emulation"... Feb 17 22:24:23 volumio volumio[21839]: info: Starting Shairport Sync Feb 17 22:24:23 volumio volumio[21839]: info: Loading plugin "last_100"... Feb 17 22:24:23 volumio volumio[21839]: info: Loading plugin "webradio"... Feb 17 22:24:23 volumio go-librespot[21919]: time="2026-02-17T22:24:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:23 volumio go-librespot[21919]: time="2026-02-17T22:24: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 17 22:24:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:23 volumio volumio[21839]: info: Loading plugin "i2s_dacs"... Feb 17 22:24:23 volumio volumio[21839]: info: Loading plugin "volumiodiscovery"... Feb 17 22:24:23 volumio volumio[21839]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 22:24:23 volumio volumio[21839]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:24:23 volumio volumio[21839]: *** WARNING *** For more information see Feb 17 22:24:23 volumio volumio[21839]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 22:24:23 volumio volumio[21839]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:24:23 volumio volumio[21839]: *** WARNING *** For more information see Feb 17 22:24:23 volumio node[21839]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 22:24:23 volumio node[21839]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:24:23 volumio node[21839]: *** WARNING *** For more information see Feb 17 22:24:23 volumio node[21839]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 22:24:23 volumio node[21839]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 22:24:23 volumio node[21839]: *** WARNING *** For more information see Feb 17 22:24:23 volumio volumio[21839]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 22:24:23 volumio volumio[21839]: info: Discovery: Started advertising with name: Volumio Feb 17 22:24:23 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 22:24:23 volumio volumio[21839]: info: Loading plugin "spop"... Feb 17 22:24:25 volumio volumio[21839]: info: Loading plugin "ytcr"... Feb 17 22:24:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 17 22:24:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:26 volumio go-librespot[21929]: go-librespot daemon starting... Feb 17 22:24:26 volumio go-librespot[21930]: time="2026-02-17T22:24:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:26 volumio go-librespot[21930]: time="2026-02-17T22:24:26+07:00" level=debug msg="app state loaded" Feb 17 22:24:26 volumio go-librespot[21930]: time="2026-02-17T22:24:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:27 volumio go-librespot[21930]: time="2026-02-17T22:24:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 22:24:27 volumio go-librespot[21930]: time="2026-02-17T22:24:27+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 17 22:24:27 volumio go-librespot[21930]: time="2026-02-17T22:24:27+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 17 22:24:27 volumio go-librespot[21930]: time="2026-02-17T22:24:27+07:00" level=info msg="zeroconf server listening on port 37167" Feb 17 22:24:27 volumio go-librespot[21930]: time="2026-02-17T22:24:27+07:00" level=debug msg="obtained new client token: AAAopF+K+9CrmD66WHH90Rzl3LgbzmVIFhKD6rmJ+8EusjNlNLde23ZX+P3tuOnYI7W1nNgrcRNs/Bpo2MbskNFU6QjAOrUMtTHoiae1MZwz41c+eEkQ+YiG4JOjC1x4syuQ5dkB5NufKMCtAjknRdC0KRd1qDubDvX0SXcup23l5xqvmPfOM5ArlEok6w39wx1xuWYAzEkedSIOmDtMmo1eUDByKl39Cpf4xcjeme3Mt2Kks8U891MNvQ==" Feb 17 22:24:27 volumio go-librespot[21930]: time="2026-02-17T22:24:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:27 volumio go-librespot[21930]: time="2026-02-17T22:24:27+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 17 22:24:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:28 volumio volumio[21839]: info: Loading plugin "ytmusic"... Feb 17 22:24:28 volumio volumio-remote-updater[25144]: [2026-02-17 22:24:28] [connect] Successful connection Feb 17 22:24:29 volumio volumio[21839]: info: Loading plugin "outputs"... Feb 17 22:24:29 volumio volumio[21839]: info: Loading plugin "albumart"... Feb 17 22:24:29 volumio volumio[21839]: info: Plugin example_plugin is not enabled Feb 17 22:24:29 volumio volumio[21839]: info: Loading plugin "inputs"... Feb 17 22:24:29 volumio volumio[21839]: info: Loading plugin "updater_comm"... Feb 17 22:24:29 volumio volumio[21839]: info: Plugin mpdemulation is not enabled Feb 17 22:24:29 volumio volumio[21839]: info: Loading plugin "rest_api"... Feb 17 22:24:29 volumio volumio[21839]: info: Loading plugin "websocket"... Feb 17 22:24:29 volumio volumio[21839]: info: Starting Socket.io Server version 1.7.4 Feb 17 22:24:29 volumio volumio[21839]: info: Loading plugin "RoonBridge"... Feb 17 22:24:30 volumio volumio[21839]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 22:24:30 volumio volumio[21839]: info: Loading i18n strings for locale en Feb 17 22:24:30 volumio volumio[21839]: Updating browse sources language Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:24:30 volumio volumio[21951]: Forking 3 albumart workers Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::initPlayerControls Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 22:24:30 volumio volumio[21839]: Express server listening on port 3000 Feb 17 22:24:30 volumio volumio[21839]: [Metrics] WebUI: 16s 63.04ms Feb 17 22:24:30 volumio volumio[21839]: info: CoreStateMachine::resetVolumioState Feb 17 22:24:30 volumio volumio[21839]: info: CoreStateMachine::getcurrentVolume Feb 17 22:24:30 volumio volumio[21839]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 22:24:30 volumio volumio[21839]: info: Volumio Network Manager: Network status updated: 1 Feb 17 22:24:30 volumio sudo[21994]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 22:24:30 volumio sudo[21994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:30 volumio sudo[21997]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 22:24:30 volumio sudo[21997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:30 volumio sudo[21994]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:30 volumio sudo[21997]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 17 22:24:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:30 volumio go-librespot[22004]: go-librespot daemon starting... Feb 17 22:24:31 volumio volumio[21839]: info: VolumeController:: Volume=100 Mute =false Feb 17 22:24:31 volumio go-librespot[22005]: time="2026-02-17T22:24:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:31 volumio go-librespot[22005]: time="2026-02-17T22:24:31+07:00" level=debug msg="app state loaded" Feb 17 22:24:31 volumio go-librespot[22005]: time="2026-02-17T22:24:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:31 volumio volumio[21839]: info: CoreStateMachine::pushState Feb 17 22:24:31 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:31 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:24:31 volumio volumio[21839]: info: CoreCommandRouter::volumioPushState Feb 17 22:24:31 volumio volumio[21839]: info: CoreStateMachine::updateTrackBlock Feb 17 22:24:31 volumio volumio[21839]: info: CorePlayQueue::getTrackBlock Feb 17 22:24:31 volumio volumio[21839]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 22:24:31 volumio volumio-remote-updater[25144]: [2026-02-17 22:24:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771341868 101 Feb 17 22:24:31 volumio volumio[21839]: 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 17 22:24:31 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:24:31 volumio volumio[21839]: info: Reloading queue from file Feb 17 22:24:31 volumio volumio[21839]: info: CoreStateMachine::setRepeat null single undefined Feb 17 22:24:31 volumio volumio[21839]: info: CoreStateMachine::pushState Feb 17 22:24:31 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:31 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 22:24:31 volumio volumio[21839]: info: CoreCommandRouter::volumioPushState Feb 17 22:24:31 volumio volumio[21839]: info: CoreStateMachine::setRandom null Feb 17 22:24:31 volumio volumio[21839]: info: CoreStateMachine::pushState Feb 17 22:24:31 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:31 volumio volumio[21839]: info: CoreCommandRouter::volumioPushState Feb 17 22:24:31 volumio volumio[21839]: info: Setting Device type: Raspberry PI Feb 17 22:24:31 volumio volumio[21839]: info: Completed loading Core Plugins Feb 17 22:24:31 volumio volumio[21839]: info: Preparing to generate the ALSA configuration file Feb 17 22:24:31 volumio volumio[21839]: info: VolumeController:: Volume=100 Mute =false Feb 17 22:24:31 volumio volumio[21839]: info: CoreStateMachine::pushState Feb 17 22:24:31 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:31 volumio volumio[21839]: info: CoreCommandRouter::volumioPushState Feb 17 22:24:31 volumio go-librespot[22005]: time="2026-02-17T22:24:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:24:31 volumio go-librespot[22005]: time="2026-02-17T22:24:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 22:24:31 volumio go-librespot[22005]: time="2026-02-17T22:24:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 22:24:31 volumio go-librespot[22005]: time="2026-02-17T22:24:31+07:00" level=info msg="zeroconf server listening on port 35859" Feb 17 22:24:31 volumio volumio[21839]: info: Asound.conf file unchanged, so no further update is needed Feb 17 22:24:31 volumio volumio[21839]: info: Output device has changed, restarting MPD Feb 17 22:24:31 volumio volumio[21839]: info: Output device has changed, restarting Shairport Sync Feb 17 22:24:31 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:31 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:24:31 volumio sudo[22024]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 22:24:31 volumio sudo[22024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:31 volumio sudo[22022]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 22:24:31 volumio sudo[22022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:31 volumio sudo[22027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 22:24:31 volumio sudo[22027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:31 volumio sudo[22024]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:31 volumio volumio[21839]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 22:24:31 volumio volumio[21839]: info: ___________ START PLUGINS ___________ Feb 17 22:24:31 volumio volumio[21839]: info: ControllerMpd::onStart: Initializing MPD Feb 17 22:24:31 volumio volumio[21839]: info: Creating MPD Configuration file Feb 17 22:24:32 volumio go-librespot[22005]: time="2026-02-17T22:24:32+07:00" level=debug msg="obtained new client token: AACCUW70v7Le3WXLm77h8Ro1JOdgIBN8jSoZISDi07kG4vaQ1RJZed8C16vL2adBzfBTQI3Uh4bPYJY8Hwv2YsvwGnLAVEQTOpD8tNxjlUnZ124KEKeL1itvvKdtywQWnYLs4WcYRj6Aal28nLBYRKet7ii/nODoty9VOTK62u2vO2Iv02id12GIWUaPzpZkiVG1UUbz2sD82SEyZwF24cd6P0B3w+O0LSjD/j/Z9BRv51/GwRSqzocs+g==" Feb 17 22:24:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 22:24:32 volumio sudo[22022]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:24:32 volumio volumio[21839]: info: [1771341872090] CoreMusicLibrary::Adding element Media Servers Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:24:32 volumio sudo[22035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 22:24:32 volumio sudo[22035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:32 volumio sudo[22035]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:32 volumio sudo[22037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 22:24:32 volumio sudo[22037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:32 volumio go-librespot[22005]: time="2026-02-17T22:24:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:32 volumio volumio[21839]: info: UPNP Browser: Client initialized successfully Feb 17 22:24:32 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 22:24:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 22:24:32 volumio systemd[1]: mpd.service: Consumed 7.100s CPU time. Feb 17 22:24:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 22:24:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 22:24:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 22:24:32 volumio go-librespot[22005]: time="2026-02-17T22:24:32+07:00" level=debug msg="completed keyexchange" Feb 17 22:24:32 volumio go-librespot[22005]: time="2026-02-17T22:24:32+07:00" level=debug msg="completed challenge" Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:24:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 22:24:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 22:24:32 volumio go-librespot[22005]: time="2026-02-17T22:24:32+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 17 22:24:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:32 volumio volumio[21839]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:24:32 volumio volumio[21839]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:24:32 volumio volumio[21839]: info: [1771341872537] CoreMusicLibrary::Adding element Last_100 Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:24:32 volumio volumio[21839]: info: [1771341872558] CoreMusicLibrary::Adding element Webradio Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 22:24:32 volumio volumio[21839]: info: Initializing BBC Radios Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:24:32 volumio sudo[22043]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 22:24:32 volumio sudo[22043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 22:24:32 volumio sudo[22043]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:32 volumio volumio[21839]: info: Creating Spotify config file Feb 17 22:24:32 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:33 volumio volumio[21962]: Starting albumart workers Feb 17 22:24:33 volumio volumio[21963]: Starting albumart workers Feb 17 22:24:33 volumio volumio[21839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:24:33 volumio volumio[21839]: info: [1771341873811] CoreMusicLibrary::Adding element YouTube Music Feb 17 22:24:33 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:24:33 volumio volumio[21839]: Cannot find translation for source YouTube Music Feb 17 22:24:33 volumio volumio[21839]: info: Volumio Calling Home Feb 17 22:24:33 volumio sudo[22068]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 22:24:33 volumio sudo[22068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:34 volumio sudo[22068]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:34 volumio volumio[21964]: Starting albumart workers Feb 17 22:24:34 volumio volumio[21839]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 22:24:34 volumio volumio[21839]: info: Discovery: Found device Volumio Feb 17 22:24:34 volumio volumio[21839]: info: CoreCommandRouter::volumioGetState Feb 17 22:24:34 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:35 volumio volumio[21839]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 22:24:35 volumio volumio[21839]: info: Discovery: Found device Volumio Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::volumioGetState Feb 17 22:24:35 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:35 volumio volumio[21839]: info: MPD Permissions set Feb 17 22:24:35 volumio volumio[21839]: info: MPD Permissions set Feb 17 22:24:35 volumio volumio[21839]: info: Upmpdcli Daemon Started Feb 17 22:24:35 volumio volumio[21839]: info: Volumio called home Feb 17 22:24:35 volumio volumio[21839]: info: Spotify config file written Feb 17 22:24:35 volumio sudo[22086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 22:24:35 volumio sudo[22086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:35 volumio volumio[21839]: 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 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 17 22:24:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:35 volumio go-librespot[22093]: go-librespot daemon starting... Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:24:35 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 22:24:35 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 22:24:35 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 22:24:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:35 volumio volumio[21839]: info: No need to fix Spotify hosts Feb 17 22:24:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:35 volumio go-librespot[22104]: go-librespot daemon starting... Feb 17 22:24:35 volumio sudo[22086]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:35 volumio go-librespot[22105]: time="2026-02-17T22:24:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:35 volumio go-librespot[22105]: time="2026-02-17T22:24:35+07:00" level=debug msg="app state loaded" Feb 17 22:24:35 volumio go-librespot[22105]: time="2026-02-17T22:24:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:36 volumio go-librespot[22105]: time="2026-02-17T22:24:36+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 17 22:24:36 volumio go-librespot[22105]: time="2026-02-17T22:24:36+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 17 22:24:36 volumio go-librespot[22105]: time="2026-02-17T22:24:36+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 17 22:24:36 volumio go-librespot[22105]: time="2026-02-17T22:24:36+07:00" level=info msg="zeroconf server listening on port 37757" Feb 17 22:24:36 volumio volumio[21839]: info: Starting Shairport Sync Feb 17 22:24:36 volumio volumio[21839]: info: Starting Shairport Sync Feb 17 22:24:36 volumio volumio[21839]: info: Starting Shairport Sync Feb 17 22:24:36 volumio go-librespot[22105]: time="2026-02-17T22:24:36+07:00" level=debug msg="obtained new client token: AAAgnPv1tGmuux89P2LcIwSsjVy5NVNrPrNZKESHr9cxQhRE9esz/oThVm2wX1sY6rKzbvAcGeCvbPGWE92RjdRR0IUU+6Vc7mDRPzjVQBBxWYElDkChjH6nyWzj3mn3FiN3064RPhdtPwYQglghpMlSx/L29YyUguWfBIoI1J4AQEDd0CfaPopd+PDCWTOFzCY3eZvv0VeP3zSY29HVMUZe36QoUssUNzvUc6Mj0oCM0srRITZb+5t/Kw==" Feb 17 22:24:36 volumio sudo[22119]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 22:24:36 volumio sudo[22119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:36 volumio sudo[22121]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 22:24:36 volumio sudo[22123]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 22:24:36 volumio sudo[22121]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:36 volumio sudo[22123]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:36 volumio go-librespot[22105]: time="2026-02-17T22:24:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:36 volumio go-librespot[22105]: time="2026-02-17T22:24:36+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 17 22:24:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:36 volumio volumio[21839]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 22:24:36 volumio volumio[21839]: SPOTIFY: BQCFG0SCP7mGL_kGR2fq9gwCHsMsPL3i5GGTsrlzDbn5sVdAr568LzKdXdzAr_JUcajzDopTy7bpZkv9crnUpim06s9QwjmHn9mUKAQNieBmNlR1etQ84GQ0S7tGdFXPa8SpjcVsCD2ixPcZ_DW-QMwiuE2VGw8Ob0feyunn4tGzDdiBCu2EO61e4d2QQEkwHuH_ePTIhYiKmv4jUBdC2eiqcJvq6OXOeXFWu2V__ZtpfnDPHA-T-1zaFgHBwd_25yF0tNf2VtUMG5iYJwbp0lIZd4cL10fTdaqGcIyr6FjUOh8Dfa_b0AYz Feb 17 22:24:36 volumio volumio[21839]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 22:24:36 volumio volumio[21839]: info: New Spotify access token = BQCFG0SCP7mGL_kGR2fq9gwCHsMsPL3i5GGTsrlzDbn5sVdAr568LzKdXdzAr_JUcajzDopTy7bpZkv9crnUpim06s9QwjmHn9mUKAQNieBmNlR1etQ84GQ0S7tGdFXPa8SpjcVsCD2ixPcZ_DW-QMwiuE2VGw8Ob0feyunn4tGzDdiBCu2EO61e4d2QQEkwHuH_ePTIhYiKmv4jUBdC2eiqcJvq6OXOeXFWu2V__ZtpfnDPHA-T-1zaFgHBwd_25yF0tNf2VtUMG5iYJwbp0lIZd4cL10fTdaqGcIyr6FjUOh8Dfa_b0AYz Feb 17 22:24:36 volumio volumio[21839]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 22:24:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 22:24:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 22:24:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 22:24:36 volumio systemd[1]: shairport-sync.service: Consumed 2.231s CPU time. Feb 17 22:24:36 volumio volumio[21839]: info: CoreCommandRouter::volumioGetState Feb 17 22:24:36 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 22:24:37 volumio sudo[22123]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:37 volumio sudo[22119]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:37 volumio sudo[22121]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:37 volumio volumio[21839]: info: Shairport-Sync Started Feb 17 22:24:37 volumio volumio[21839]: Error adding Membership: Error: addMembership EINVAL Feb 17 22:24:37 volumio volumio[21839]: info: Shairport-Sync Started Feb 17 22:24:37 volumio volumio[21839]: info: Shairport-Sync Started Feb 17 22:24:37 volumio volumio[21839]: 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 17 22:24:37 volumio volumio[21839]: info: Spotify Successfully logged in Feb 17 22:24:37 volumio volumio[21839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 22:24:37 volumio volumio[21839]: info: [1771341877405] CoreMusicLibrary::Adding element Spotify Feb 17 22:24:37 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 22:24:37 volumio volumio[21839]: Cannot find translation for source YouTube Music Feb 17 22:24:37 volumio volumio[21839]: Cannot find translation for source Spotify Feb 17 22:24:38 volumio volumio[21839]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 22:24:38 volumio volumio[21839]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 22:24:38 volumio volumio[21839]: info: VolumeController:: Volume=100 Mute =false Feb 17 22:24:38 volumio volumio[21839]: info: CoreCommandRouter::volumioGetState Feb 17 22:24:38 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:38 volumio volumio[21839]: info: CoreStateMachine::pushState Feb 17 22:24:38 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:38 volumio volumio[21839]: info: CoreCommandRouter::volumioPushState Feb 17 22:24:39 volumio volumio[21839]: info: go-librespot daemon successfully initialized Feb 17 22:24:39 volumio mpd[22066]: 2026-02-17T22:24:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 22:24:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 22:24:39 volumio sudo[22027]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:39 volumio sudo[22037]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:39 volumio volumio[21839]: error: MPD error: The expression evaluated to a falsy value: Feb 17 22:24:39 volumio volumio[21839]: assert.ok(self.idling) Feb 17 22:24:39 volumio volumio[21839]: error: The expression evaluated to a falsy value: Feb 17 22:24:39 volumio volumio[21839]: assert.ok(self.idling) Feb 17 22:24:39 volumio volumio[21839]: info: MPD running with PID22066 Feb 17 22:24:39 volumio volumio[21839]: ,establishing connection Feb 17 22:24:39 volumio volumio[21839]: error: updateQueue error: null Feb 17 22:24:39 volumio volumio[21839]: info: Completed starting Core Plugins Feb 17 22:24:39 volumio volumio[21839]: info: ------------------------------------------- Feb 17 22:24:39 volumio volumio[21839]: info: ----- MyVolumio plugins startup ---- Feb 17 22:24:39 volumio volumio[21839]: info: ------------------------------------------- Feb 17 22:24:39 volumio volumio[21839]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 22:24:39 volumio volumio[21839]: error: updateQueue error: null Feb 17 22:24:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 22:24:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:40 volumio go-librespot[22166]: go-librespot daemon starting... Feb 17 22:24:40 volumio go-librespot[22167]: time="2026-02-17T22:24:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:40 volumio go-librespot[22167]: time="2026-02-17T22:24:40+07:00" level=debug msg="app state loaded" Feb 17 22:24:40 volumio go-librespot[22167]: time="2026-02-17T22:24:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:40 volumio go-librespot[22167]: time="2026-02-17T22:24:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 22:24:40 volumio go-librespot[22167]: time="2026-02-17T22:24:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 22:24:40 volumio go-librespot[22167]: time="2026-02-17T22:24:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 22:24:40 volumio go-librespot[22167]: time="2026-02-17T22:24:40+07:00" level=info msg="zeroconf server listening on port 45033" Feb 17 22:24:40 volumio go-librespot[22167]: time="2026-02-17T22:24:40+07:00" level=debug msg="obtained new client token: AAAv+6Vxi/sAAa8U75in9p828mD82p6YWD2uBwg2DFFa/5E32ftmHQ6+N4jZK6kjcz31Jg4AjqGSM6poUllzNJsxb+kbjGORI9KtWo5xWfUUSypZ4OkpfOy6Yio57QqlBEhIxsydo4D3plI9bS2CcfFhaloQOHmOAJt+PJ3kKKIT0B1EqgLx2zOKu6teIqQPdnVQ5ndWM6Ak9Raw4tQSkCkF3OzxsvhfTWSa57DoWt77G7ARJJLnlJ86zw==" Feb 17 22:24:40 volumio go-librespot[22167]: time="2026-02-17T22:24:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:41 volumio go-librespot[22167]: time="2026-02-17T22:24:41+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 17 22:24:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:42 volumio volumio[21839]: info: Initializing connection to go-librespot Websocket Feb 17 22:24:42 volumio volumio[21839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 22:24:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 22:24:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:44 volumio go-librespot[22174]: go-librespot daemon starting... Feb 17 22:24:44 volumio go-librespot[22175]: time="2026-02-17T22:24:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:44 volumio go-librespot[22175]: time="2026-02-17T22:24:44+07:00" level=debug msg="app state loaded" Feb 17 22:24:44 volumio go-librespot[22175]: time="2026-02-17T22:24:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:44 volumio go-librespot[22175]: time="2026-02-17T22:24:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:24:44 volumio go-librespot[22175]: time="2026-02-17T22:24:44+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 17 22:24:44 volumio go-librespot[22175]: time="2026-02-17T22:24:44+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 17 22:24:44 volumio go-librespot[22175]: time="2026-02-17T22:24:44+07:00" level=info msg="zeroconf server listening on port 46281" Feb 17 22:24:44 volumio volumio[21839]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 22:24:44 volumio go-librespot[22175]: time="2026-02-17T22:24:44+07:00" level=debug msg="obtained new client token: AACxcgj4ViuD8GeXK4E8xTzUJyxsCheU487CtHfLKdtnhMV8J/KLXzNnVcHzLp+CKY6KlMpEkQzTfNbtv4i1IkfDnGj/yx/5TGIyRmol0RX9BLKCntcULAH+royHAYgoPrJoHuKxmO6hLEgLICh3QI3LAi0p0zbMoplPlI3cWXFkogQ6CkDby80im8pqug5Ra1LkeSUPuqj9Z+tTSzzF2Kxkiaz5o8X6wyF7mk9UjzOX4N7LpuyUvecWOQ==" Feb 17 22:24:44 volumio go-librespot[22175]: time="2026-02-17T22:24:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:45 volumio go-librespot[22175]: time="2026-02-17T22:24:45+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 17 22:24:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:45 volumio volumio[21839]: info: Initializing connection to go-librespot Websocket Feb 17 22:24:45 volumio volumio[21839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 22:24:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 22:24:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:48 volumio go-librespot[22182]: go-librespot daemon starting... Feb 17 22:24:48 volumio go-librespot[22183]: time="2026-02-17T22:24:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:48 volumio go-librespot[22183]: time="2026-02-17T22:24:48+07:00" level=debug msg="app state loaded" Feb 17 22:24:48 volumio go-librespot[22183]: time="2026-02-17T22:24:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:48 volumio volumio[21839]: info: Initializing connection to go-librespot Websocket Feb 17 22:24:48 volumio go-librespot[22183]: time="2026-02-17T22:24:48+07:00" level=debug msg="new websocket client" Feb 17 22:24:48 volumio volumio[21839]: info: Connection to go-librespot Websocket established Feb 17 22:24:48 volumio go-librespot[22183]: time="2026-02-17T22:24: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 17 22:24:48 volumio go-librespot[22183]: time="2026-02-17T22:24: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 17 22:24:48 volumio go-librespot[22183]: time="2026-02-17T22:24: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 17 22:24:48 volumio go-librespot[22183]: time="2026-02-17T22:24:48+07:00" level=info msg="zeroconf server listening on port 38971" Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 22:24:48 volumio volumio[21839]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 22:24:48 volumio volumio[21839]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 22:24:48 volumio volumio[21839]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 22:24:48 volumio volumio[21839]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 22:24:48 volumio volumio[21839]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 22:24:48 volumio volumio[21839]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 22:24:48 volumio volumio[21839]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 22:24:48 volumio volumio[21839]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 22:24:48 volumio go-librespot[22183]: time="2026-02-17T22:24:48+07:00" level=debug msg="obtained new client token: AAB9SyKu0q/ZSMko7yZSA1w8QbRmzEJgFF1KGaaHeLgmJNROOaZQlBPInhjJLa9RAhlDoEl8dh/OzDP3j1dDQOcKvqmte0xpuLH/sLxdyGbDhX+V39wNy5kJr7cLdFyR2JMoVM51UneTNNF9cHMYp8TbaBfuVTi9UOnTB9vCxX8osu353wXdL01OzppLHry1rw2fx9CF8XwavsLg0dYACBPbk6xqrQ020LDXt9f0HW90K5oBWaBgzCpanA==" Feb 17 22:24:48 volumio go-librespot[22183]: time="2026-02-17T22:24:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:49 volumio go-librespot[22183]: time="2026-02-17T22:24:49+07:00" level=debug msg="completed keyexchange" Feb 17 22:24:49 volumio go-librespot[22183]: time="2026-02-17T22:24:49+07:00" level=debug msg="completed challenge" Feb 17 22:24:49 volumio go-librespot[22183]: time="2026-02-17T22:24:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 22:24:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:50 volumio volumio[21839]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 22:24:50 volumio volumio[21839]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 22:24:50 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:24:50 volumio volumio[21839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 22:24:50 volumio volumio[21839]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 22:24:50 volumio volumio[21839]: info: MyVolumio login type: Token Feb 17 22:24:50 volumio volumio[21839]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 22:24:50 volumio volumio[21839]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 22:24:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 17 22:24:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 22:24:52 volumio go-librespot[22205]: go-librespot daemon starting... Feb 17 22:24:52 volumio volumio[21839]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 22:24:52 volumio volumio[21839]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 22:24:52 volumio volumio[21839]: info: Streaming services startup Feb 17 22:24:52 volumio volumio[21839]: info: Starting Streaming Daemon Feb 17 22:24:52 volumio go-librespot[22206]: time="2026-02-17T22:24:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 22:24:52 volumio go-librespot[22206]: time="2026-02-17T22:24:52+07:00" level=debug msg="app state loaded" Feb 17 22:24:52 volumio go-librespot[22206]: time="2026-02-17T22:24:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 22:24:52 volumio sudo[22213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 22:24:52 volumio sudo[22213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 22:24:52 volumio volumio[21839]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 22:24:52 volumio sudo[22213]: pam_unix(sudo:session): session closed for user root Feb 17 22:24:52 volumio volumio[21839]: info: Getting Spotify volume Feb 17 22:24:52 volumio volumio[21839]: info: Connection to go-librespot Websocket closed Feb 17 22:24:52 volumio volumio[21839]: error: Cannot start Volumio Streaming Daemon Feb 17 22:24:52 volumio volumio[21839]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 22:24:52 volumio volumio[21839]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 22:24:52 volumio volumio[21839]: 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 17 22:24:52 volumio volumio[21839]: info: CoreCommandRouter::volumioGetState Feb 17 22:24:52 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:52 volumio go-librespot[22206]: time="2026-02-17T22:24:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 22:24:52 volumio go-librespot[22206]: time="2026-02-17T22:24:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 22:24:52 volumio go-librespot[22206]: time="2026-02-17T22:24:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 22:24:52 volumio volumio[21839]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 17 22:24:52 volumio volumio[21839]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 22:24:52 volumio volumio[21839]: SPOTIFY: VOLUMIO VOLUME 100 Feb 17 22:24:52 volumio volumio[21839]: info: Aligning Spotify Volume to Volumio Volume Feb 17 22:24:52 volumio volumio[21839]: info: CoreCommandRouter::volumioGetState Feb 17 22:24:52 volumio volumio[21839]: info: CorePlayQueue::getTrack 0 Feb 17 22:24:52 volumio volumio[21839]: info: Setting Spotify Volume from Volumio: 100 Feb 17 22:24:52 volumio go-librespot[22206]: time="2026-02-17T22:24:52+07:00" level=info msg="zeroconf server listening on port 46537" Feb 17 22:24:53 volumio go-librespot[22206]: time="2026-02-17T22:24:53+07:00" level=debug msg="obtained new client token: AADMkWnicVEjdyOMr0bST0QBuXrq7p9O+Y3uk1B3t5YtEimC891/v4JKE2Ob564GDo/uE/0dwGi3FJ6/IlFkfB3b9mMs35AF3NMGjqz9vewEs+gFf45Jxiwkn3IyDggKlmQ4FZrimtuMBNBEjM1MPH1T11QCHofihGABM8WttfjdYNaBhte4SH3Un+KG+knsPS+jpTMYDoqXsUjH/J/aALpIDkht6PeAH3aSoVL7PexpCweUDKFbfmY=" Feb 17 22:24:53 volumio go-librespot[22206]: time="2026-02-17T22:24:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 22:24:53 volumio go-librespot[22206]: time="2026-02-17T22:24:53+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 17 22:24:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 22:24:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 22:24:53 volumio volumio[21839]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 22:24:53 volumio volumio[21839]: Error: socket hang up Feb 17 22:24:53 volumio volumio[21839]: at connResetException (node:internal/errors:720:14) Feb 17 22:24:53 volumio volumio[21839]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 22:24:53 volumio volumio[21839]: at Socket.emit (node:events:526:35) Feb 17 22:24:53 volumio volumio[21839]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 22:24:53 volumio volumio[21839]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 22:24:53 volumio volumio[21839]: code: 'ECONNRESET', Feb 17 22:24:53 volumio volumio[21839]: response: undefined Feb 17 22:24:53 volumio volumio[21839]: } Feb 17 22:24:53 volumio volumio[21839]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 22:24:54 volumio sudo[22234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 22:23' Feb 17 22:24:54 volumio sudo[22234]: 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"