Mar 04 20:11:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 04 20:11:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:01 volumio go-librespot[25733]: go-librespot daemon starting... Mar 04 20:11:01 volumio go-librespot[25734]: time="2026-03-04T20:11:01+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:01 volumio go-librespot[25734]: time="2026-03-04T20:11:01+01:00" level=debug msg="app state loaded" Mar 04 20:11:01 volumio go-librespot[25734]: time="2026-03-04T20:11:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:01 volumio volumio[25723]: info: ------------------------------------------- Mar 04 20:11:01 volumio volumio[25723]: info: ----- Volumio3 ---- Mar 04 20:11:01 volumio volumio[25723]: info: ------------------------------------------- Mar 04 20:11:01 volumio volumio[25723]: info: ----- System startup ---- Mar 04 20:11:01 volumio volumio[25723]: info: ------------------------------------------- Mar 04 20:11:01 volumio go-librespot[25734]: time="2026-03-04T20:11:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:01 volumio go-librespot[25734]: time="2026-03-04T20:11:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:01 volumio go-librespot[25734]: time="2026-03-04T20:11:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:01 volumio go-librespot[25734]: time="2026-03-04T20:11:01+01:00" level=info msg="zeroconf server listening on port 41093" Mar 04 20:11:01 volumio go-librespot[25734]: time="2026-03-04T20:11:01+01:00" level=debug msg="obtained new client token: AABSHjaPzSSg4nmv8x/2F8TQnW8qNvEQCGieq2hncK8WwfZEIeOiJGliEcP4Ys8ZygDKoEdm+C4B/CptVpDoEKNWBcdIY74xAOFasBwhrGil76koCurwM6QQPkfBYSL6LiKQvBXsCvGwWrRPZLDGQoh+bW/oaYYv+pSulvpfMb15ij3vkB71U2s80GMwrlXQRYz4JOPA7/UFnl9Wh05/N6rB1ZaJWqLfFuhTofy/wm4ZInk52TQc4Zs6jA==" Mar 04 20:11:01 volumio go-librespot[25734]: time="2026-03-04T20:11:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:01 volumio go-librespot[25734]: time="2026-03-04T20:11:01+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:02 volumio go-librespot[25734]: time="2026-03-04T20:11:02+01:00" level=debug msg="completed challenge" Mar 04 20:11:02 volumio go-librespot[25734]: time="2026-03-04T20:11:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:02 volumio volumio-remote-updater[708]: [2026-03-04 20:11:02] [connect] Successful connection Mar 04 20:11:03 volumio volumio[25723]: info: MYVOLUMIO Environment detected Mar 04 20:11:03 volumio volumio[25723]: info: Plugin folders cleanup Mar 04 20:11:03 volumio volumio[25723]: info: Scanning into folder /volumio/app/plugins/ Mar 04 20:11:03 volumio volumio[25723]: info: Scanning category audio_interface Mar 04 20:11:03 volumio volumio[25723]: info: Scanning category miscellanea Mar 04 20:11:03 volumio volumio[25723]: info: Scanning category music_service Mar 04 20:11:03 volumio volumio[25723]: info: Scanning category plugins.json Mar 04 20:11:03 volumio volumio[25723]: info: Scanning category system_controller Mar 04 20:11:03 volumio volumio[25723]: info: Scanning category user_interface Mar 04 20:11:03 volumio volumio[25723]: info: Scanning into folder /data/plugins/ Mar 04 20:11:03 volumio volumio[25723]: info: Scanning category music_service Mar 04 20:11:03 volumio volumio[25723]: info: Plugin folders cleanup completed Mar 04 20:11:03 volumio volumio[25723]: info: ------------------------------------------- Mar 04 20:11:03 volumio volumio[25723]: info: ----- Core plugins startup ---- Mar 04 20:11:03 volumio volumio[25723]: info: ------------------------------------------- Mar 04 20:11:03 volumio volumio[25723]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 20:11:03 volumio volumio[25723]: info: Adding plugin upnp to MyMusic Plugins Mar 04 20:11:03 volumio volumio[25723]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 20:11:03 volumio volumio[25723]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 20:11:03 volumio volumio[25723]: info: Loading plugins from folder /data/plugins/ Mar 04 20:11:03 volumio volumio[25723]: info: Loading plugin "system"... Mar 04 20:11:03 volumio volumio[25723]: info: Loading plugin "appearance"... Mar 04 20:11:05 volumio volumio[25723]: info: Loading plugin "network"... Mar 04 20:11:05 volumio volumio[25723]: info: Refreshing Cached IP Addresses Mar 04 20:11:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 04 20:11:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:05 volumio sudo[25755]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:11:05 volumio sudo[25757]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:11:05 volumio sudo[25755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:05 volumio sudo[25757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:05 volumio volumio[25723]: info: Loading plugin "services"... Mar 04 20:11:05 volumio go-librespot[25758]: go-librespot daemon starting... Mar 04 20:11:05 volumio volumio[25723]: info: Loading plugin "volumio5onboarding"... Mar 04 20:11:05 volumio sudo[25757]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:05 volumio sudo[25755]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:05 volumio volumio[25723]: info: Loading plugin "alsa_controller"... Mar 04 20:11:05 volumio sudo[25767]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 20:11:05 volumio go-librespot[25772]: time="2026-03-04T20:11:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:05 volumio go-librespot[25772]: time="2026-03-04T20:11:05+01:00" level=debug msg="app state loaded" Mar 04 20:11:05 volumio sudo[25767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:05 volumio go-librespot[25772]: time="2026-03-04T20:11:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:05 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:11:05 volumio volumio[25723]: info: Loading plugin "wizard"... Mar 04 20:11:05 volumio volumio[25723]: info: Loading plugin "networkfs"... Mar 04 20:11:05 volumio volumio[25723]: info: Starting Udev Watcher for removable devices Mar 04 20:11:05 volumio volumio[25723]: info: Ignoring mount for partition: boot Mar 04 20:11:05 volumio volumio[25723]: info: Ignoring mount for partition: volumio Mar 04 20:11:05 volumio volumio[25723]: info: Ignoring mount for partition: volumio_data Mar 04 20:11:05 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:11:05 volumio volumio[25723]: info: Loading plugin "volumio_command_line_client"... Mar 04 20:11:05 volumio volumio[25723]: info: Loading plugin "upnp"... Mar 04 20:11:05 volumio volumio[25723]: info: [1772651465591] Starting Upmpd Daemon Mar 04 20:11:05 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:11:05 volumio volumio[25723]: info: Loading plugin "my_music"... Mar 04 20:11:05 volumio volumio[25723]: info: Loading plugin "mpd"... Mar 04 20:11:05 volumio go-librespot[25772]: time="2026-03-04T20:11:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:05 volumio go-librespot[25772]: time="2026-03-04T20:11:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:05 volumio go-librespot[25772]: time="2026-03-04T20:11:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:05 volumio go-librespot[25772]: time="2026-03-04T20:11:05+01:00" level=info msg="zeroconf server listening on port 36021" Mar 04 20:11:05 volumio go-librespot[25772]: time="2026-03-04T20:11:05+01:00" level=debug msg="obtained new client token: AABln+4Eswm6pHeEhqCtWSYuB6peZuLAwGCJcppf+rUKRr5fMRP4kOGpY5GEPF458CYu80upMxtC5DfdoyjBTwJ/CGIaC/vu9Xo2sm6Gl1ijs0QyFAnKAUQjSbM/8T/BmrODbXAXJxHqBbkR34gBtnj8x2ik0Ef8Jrec/sMCZ4GOCGyiCxcwOfI3la6eKV6WvmRCENs4hVwGJWpZInLd+z6t00k3V26RzTKvRrDaDSgT6Z/m1ESPUof1kw==" Mar 04 20:11:05 volumio go-librespot[25772]: time="2026-03-04T20:11:05+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 20:11:05 volumio sudo[25767]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:05 volumio go-librespot[25772]: time="2026-03-04T20:11:05+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Mar 04 20:11:06 volumio go-librespot[25772]: time="2026-03-04T20:11:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Mar 04 20:11:06 volumio go-librespot[25772]: time="2026-03-04T20:11:06+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:06 volumio go-librespot[25772]: time="2026-03-04T20:11:06+01:00" level=debug msg="completed challenge" Mar 04 20:11:06 volumio go-librespot[25772]: time="2026-03-04T20:11:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:06 volumio volumio[25723]: info: Loading plugin "upnp_browser"... Mar 04 20:11:06 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:06.380+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.178.147:46046 @ 0x28a2390" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 04 20:11:09 volumio volumio[25723]: info: Starting UPNP Browser Mar 04 20:11:09 volumio volumio[25723]: info: Loading plugin "alarm-clock"... Mar 04 20:11:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 04 20:11:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:09 volumio volumio[25723]: info: Loading plugin "airplay_emulation"... Mar 04 20:11:09 volumio volumio[25723]: info: Starting Shairport Sync Mar 04 20:11:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:09 volumio volumio[25723]: info: Loading plugin "last_100"... Mar 04 20:11:09 volumio go-librespot[25797]: go-librespot daemon starting... Mar 04 20:11:09 volumio volumio[25723]: info: Loading plugin "webradio"... Mar 04 20:11:09 volumio go-librespot[25798]: time="2026-03-04T20:11:09+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:09 volumio go-librespot[25798]: time="2026-03-04T20:11:09+01:00" level=debug msg="app state loaded" Mar 04 20:11:09 volumio go-librespot[25798]: time="2026-03-04T20:11:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:09 volumio volumio[25723]: info: Loading plugin "i2s_dacs"... Mar 04 20:11:09 volumio volumio[25723]: info: Loading plugin "volumiodiscovery"... Mar 04 20:11:09 volumio volumio[25723]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:11:09 volumio volumio[25723]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:11:09 volumio node[25723]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:11:09 volumio volumio[25723]: *** WARNING *** For more information see Mar 04 20:11:09 volumio volumio[25723]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:11:09 volumio volumio[25723]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:11:09 volumio volumio[25723]: *** WARNING *** For more information see Mar 04 20:11:09 volumio node[25723]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:11:09 volumio node[25723]: *** WARNING *** For more information see Mar 04 20:11:09 volumio node[25723]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:11:09 volumio node[25723]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:11:09 volumio node[25723]: *** WARNING *** For more information see Mar 04 20:11:09 volumio volumio[25723]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 20:11:09 volumio volumio[25723]: info: Discovery: Started advertising with name: Volumio Mar 04 20:11:09 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:11:09 volumio volumio[25723]: info: Loading plugin "spop"... Mar 04 20:11:09 volumio go-librespot[25798]: time="2026-03-04T20:11:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:09 volumio go-librespot[25798]: time="2026-03-04T20:11:09+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:09 volumio go-librespot[25798]: time="2026-03-04T20:11:09+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:09 volumio go-librespot[25798]: time="2026-03-04T20:11:09+01:00" level=info msg="zeroconf server listening on port 41361" Mar 04 20:11:10 volumio go-librespot[25798]: time="2026-03-04T20:11:10+01:00" level=debug msg="obtained new client token: AABVSGxTPK9Gu9pTumvSKuqLoo+q9o1cQgofkLHNJx/UEqPBYgiW4xgJRheZf9gJRL02MIxAynp5Ln72s5b4HWwTjotiDQX6x4XI5ELKx41XRX09herSCRhERLdki/WxhRSA38vuMIUW127TI2VvNGlu7M8wiNFwyjLStnu6pCKVPXneWGt4psmdMwekEk3k1rq6z8D7kzw133kHssfZVPdVbOuBEc7/1IvkQaqgQ9KWQfvOSM6ViAI=" Mar 04 20:11:10 volumio go-librespot[25798]: time="2026-03-04T20:11:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:10 volumio go-librespot[25798]: time="2026-03-04T20:11:10+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:10 volumio go-librespot[25798]: time="2026-03-04T20:11:10+01:00" level=debug msg="completed challenge" Mar 04 20:11:10 volumio go-librespot[25798]: time="2026-03-04T20:11:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:10 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:10.974+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:34186->127.0.0.1:3000: i/o timeout" Mar 04 20:11:11 volumio volumio[25723]: info: Loading plugin "outputs"... Mar 04 20:11:11 volumio volumio[25723]: info: Loading plugin "albumart"... Mar 04 20:11:11 volumio volumio[25723]: info: Plugin example_plugin is not enabled Mar 04 20:11:11 volumio volumio[25723]: info: Loading plugin "inputs"... Mar 04 20:11:11 volumio volumio[25723]: info: Loading plugin "updater_comm"... Mar 04 20:11:11 volumio volumio[25723]: info: Plugin mpdemulation is not enabled Mar 04 20:11:11 volumio volumio[25723]: info: Loading plugin "rest_api"... Mar 04 20:11:12 volumio volumio[25723]: info: Loading plugin "websocket"... Mar 04 20:11:12 volumio volumio[25723]: info: Starting Socket.io Server version 1.7.4 Mar 04 20:11:12 volumio volumio[25723]: info: Loading i18n strings for locale nl Mar 04 20:11:12 volumio volumio[25723]: Updating browse sources language Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::initPlayerControls Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: Express server listening on port 3000 Mar 04 20:11:12 volumio volumio[25723]: [Metrics] WebUI: 11s 743.03ms Mar 04 20:11:12 volumio volumio[25723]: info: CoreStateMachine::resetVolumioState Mar 04 20:11:12 volumio volumio[25723]: info: CoreStateMachine::getcurrentVolume Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:11:12 volumio volumio[25723]: info: Volumio Network Manager: Network status updated: 1 Mar 04 20:11:12 volumio volumio[25723]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Mar 04 20:11:12 volumio volumio[25808]: Forking 3 albumart workers Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:12 volumio volumio[25723]: info: Reloading queue from file Mar 04 20:11:12 volumio volumio[25723]: info: VolumeController:: Volume=5 Mute =false Mar 04 20:11:12 volumio volumio[25723]: info: CoreStateMachine::pushState Mar 04 20:11:12 volumio volumio[25723]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::volumioPushState Mar 04 20:11:12 volumio volumio[25723]: info: CoreStateMachine::updateTrackBlock Mar 04 20:11:12 volumio volumio[25723]: info: CorePlayQueue::getTrackBlock Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:11:12 volumio volumio[25723]: info: Setting Device type: Raspberry PI Mar 04 20:11:12 volumio volumio[25723]: info: CoreStateMachine::setRepeat false single undefined Mar 04 20:11:12 volumio volumio[25723]: info: CoreStateMachine::pushState Mar 04 20:11:12 volumio volumio[25723]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::volumioPushState Mar 04 20:11:12 volumio volumio[25723]: info: CoreStateMachine::setRandom undefined Mar 04 20:11:12 volumio volumio[25723]: info: CoreStateMachine::pushState Mar 04 20:11:12 volumio volumio[25723]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:11:12 volumio volumio[25723]: info: CoreCommandRouter::volumioPushState Mar 04 20:11:13 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Mar 04 20:11:13 volumio volumio[25723]: info: Completed loading Core Plugins Mar 04 20:11:13 volumio volumio[25723]: info: Preparing to generate the ALSA configuration file Mar 04 20:11:13 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Mar 04 20:11:13 volumio volumio[25723]: info: VolumeController:: Volume=5 Mute =false Mar 04 20:11:13 volumio volumio[25723]: info: CoreStateMachine::pushState Mar 04 20:11:13 volumio volumio[25723]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:13 volumio volumio[25723]: info: CoreCommandRouter::volumioPushState Mar 04 20:11:13 volumio volumio[25723]: info: Asound.conf file unchanged, so no further update is needed Mar 04 20:11:13 volumio volumio[25723]: info: Output device has changed, restarting MPD Mar 04 20:11:13 volumio volumio[25723]: info: Output device has changed, restarting Shairport Sync Mar 04 20:11:13 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:13 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 04 20:11:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:13 volumio sudo[25864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:11:13 volumio sudo[25864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:13 volumio sudo[25866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:11:13 volumio sudo[25864]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:13 volumio sudo[25866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:13 volumio volumio[25723]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:11:13 volumio go-librespot[25871]: go-librespot daemon starting... Mar 04 20:11:13 volumio volumio[25723]: info: ___________ START PLUGINS ___________ Mar 04 20:11:13 volumio volumio[25723]: info: ControllerMpd::onStart: Initializing MPD Mar 04 20:11:13 volumio volumio[25723]: info: Creating MPD Configuration file Mar 04 20:11:13 volumio sudo[25881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 04 20:11:13 volumio sudo[25881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:13 volumio go-librespot[25874]: time="2026-03-04T20:11:13+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:13 volumio go-librespot[25874]: time="2026-03-04T20:11:13+01:00" level=debug msg="app state loaded" Mar 04 20:11:13 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:11:13 volumio go-librespot[25874]: time="2026-03-04T20:11:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:13 volumio volumio[25723]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:11:13 volumio volumio[25723]: info: [1772651473598] CoreMusicLibrary::Adding element Media Servers Mar 04 20:11:13 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:11:13 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 20:11:13 volumio sudo[25884]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:11:13 volumio sudo[25884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:13 volumio sudo[25886]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:11:13 volumio sudo[25886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:13 volumio volumio[25723]: info: UPNP Browser: Client initialized successfully Mar 04 20:11:13 volumio sudo[25884]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:13 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:11:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:11:13 volumio systemd[1]: mpd.service: Consumed 6.803s CPU time. Mar 04 20:11:13 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:11:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:11:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:11:13 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:11:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:11:13 volumio volumio[25723]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:11:13 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:13 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:13 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:11:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:11:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:11:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:11:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:11:14 volumio sudo[25881]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:14 volumio volumio[25723]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:11:14 volumio volumio[25723]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:11:14 volumio volumio[25723]: info: [1772651474061] CoreMusicLibrary::Adding element Last_100 Mar 04 20:11:14 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:11:14 volumio volumio[25723]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:11:14 volumio volumio[25723]: info: [1772651474081] CoreMusicLibrary::Adding element Webradio Mar 04 20:11:14 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:11:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:11:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:11:14 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:11:14 volumio volumio[25723]: info: Initializing BBC Radios Mar 04 20:11:14 volumio go-librespot[25874]: time="2026-03-04T20:11:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:14 volumio go-librespot[25874]: time="2026-03-04T20:11:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:14 volumio go-librespot[25874]: time="2026-03-04T20:11:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:14 volumio go-librespot[25874]: time="2026-03-04T20:11:14+01:00" level=info msg="zeroconf server listening on port 37379" Mar 04 20:11:14 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:11:14 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:14 volumio volumio[25723]: info: Creating Spotify config file Mar 04 20:11:14 volumio go-librespot[25874]: time="2026-03-04T20:11:14+01:00" level=debug msg="obtained new client token: AABFs99rjCe9uIaTXBpETrGx6uVeWe9CbzHQcPlOrbd9OvrikQUlWADPz36nDFVw51BpC8crKETiHP0gOxPF+BJcIp7vtV6naVDb1dxgwHFAPSTSMq4jG5T119BD26QxZiMZKq/hW/q9aehTIiaTsi5zj9S8WxomK0pJSrOPm6g/7lp6cOMm//7KdsWtyq1wVsDxwEXCdEABkLvCW19dEGKdGnojoKH9UKT3exJUA81BClnCGMKM2CwhBw==" Mar 04 20:11:14 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:14 volumio go-librespot[25874]: time="2026-03-04T20:11:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:14 volumio go-librespot[25874]: time="2026-03-04T20:11:14+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:14 volumio go-librespot[25874]: time="2026-03-04T20:11:14+01:00" level=debug msg="completed challenge" Mar 04 20:11:14 volumio go-librespot[25874]: time="2026-03-04T20:11:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:14 volumio sudo[25903]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 20:11:14 volumio sudo[25903]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 20:11:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:14 volumio sudo[25903]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:15 volumio volumio-remote-updater[708]: [2026-03-04 20:11:15] [connect] Successful connection Mar 04 20:11:15 volumio volumio[25723]: info: Volumio Calling Home Mar 04 20:11:16 volumio volumio[25826]: Starting albumart workers Mar 04 20:11:16 volumio volumio[25825]: Starting albumart workers Mar 04 20:11:16 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Mar 04 20:11:16 volumio volumio[25827]: Starting albumart workers Mar 04 20:11:16 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:16.378+01:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get system info: could not get system info: context deadline exceeded" Mar 04 20:11:16 volumio sudo[25938]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:11:16 volumio volumio[25723]: info: Discovery: adding 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 20:11:16 volumio volumio[25723]: info: Discovery: Found device Volumio Mar 04 20:11:16 volumio sudo[25938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:16 volumio volumio[25723]: info: CoreCommandRouter::volumioGetState Mar 04 20:11:16 volumio volumio[25723]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:16 volumio sudo[25938]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:16 volumio sudo[25939]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:11:16 volumio sudo[25939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:16 volumio volumio[25723]: info: Discovery: this is already registered, 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 20:11:16 volumio volumio[25723]: info: Discovery: Found device Volumio Mar 04 20:11:16 volumio volumio[25723]: info: CoreCommandRouter::volumioGetState Mar 04 20:11:16 volumio volumio[25723]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:16 volumio sudo[25939]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:16 volumio volumio[25723]: info: MPD Permissions set Mar 04 20:11:16 volumio volumio[25723]: info: MPD Permissions set Mar 04 20:11:16 volumio volumio-remote-updater[708]: [2026-03-04 20:11:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772651475 101 Mar 04 20:11:16 volumio volumio[25723]: 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: 2 Mar 04 20:11:16 volumio volumio[25723]: info: Volumio called home Mar 04 20:11:16 volumio volumio[25723]: info: Spotify config file written Mar 04 20:11:17 volumio sudo[25943]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 20:11:17 volumio sudo[25943]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:17 volumio go-librespot[25945]: go-librespot daemon starting... Mar 04 20:11:17 volumio sudo[25943]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:17 volumio go-librespot[25946]: time="2026-03-04T20:11:17+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:17 volumio go-librespot[25946]: time="2026-03-04T20:11:17+01:00" level=debug msg="app state loaded" Mar 04 20:11:17 volumio go-librespot[25946]: time="2026-03-04T20:11:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:17 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio go-librespot[25946]: time="2026-03-04T20:11:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:17 volumio go-librespot[25946]: time="2026-03-04T20:11:17+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:17 volumio go-librespot[25946]: time="2026-03-04T20:11:17+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio go-librespot[25946]: time="2026-03-04T20:11:17+01:00" level=info msg="zeroconf server listening on port 43255" Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:17 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:18 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:18 volumio volumio[25723]: info: No need to fix Spotify hosts Mar 04 20:11:18 volumio go-librespot[25946]: time="2026-03-04T20:11:18+01:00" level=debug msg="obtained new client token: AADGLXYO8AdIB1sn0CnEecfVLCZ2GjaBWg36xhWBF00PnDWWTNZVVQpTgsAjz1s391h4+YRIO7KJiStRFeM32oiMbWBnEocToN9VlXO7e4O/nOg02kI7WV5GRdgETxfjK8Q38CrlcZSRGa7cMks8CsgiSBpbgSHvSs4SZqsHB87UFv1KhrE+V+9/MYpp8ySkfRYB/W2HiNVSk+FpCidUYz+30okSz6qSJn8D27Gxcm/NLOq5sUXwD2U=" Mar 04 20:11:18 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 04 20:11:18 volumio go-librespot[25946]: time="2026-03-04T20:11:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:18 volumio go-librespot[25946]: time="2026-03-04T20:11:18+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:18 volumio go-librespot[25946]: time="2026-03-04T20:11:18+01:00" level=debug msg="completed challenge" Mar 04 20:11:18 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:11:18 volumio go-librespot[25946]: time="2026-03-04T20:11:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:18 volumio volumio[25723]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 04 20:11:18 volumio volumio[25723]: info: Starting Shairport Sync Mar 04 20:11:18 volumio volumio[25723]: info: Starting Shairport Sync Mar 04 20:11:18 volumio volumio[25723]: info: Starting Shairport Sync Mar 04 20:11:18 volumio sudo[25978]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:11:18 volumio sudo[25980]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:11:18 volumio sudo[25980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:18 volumio sudo[25978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:18 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:11:18 volumio sudo[25982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:11:18 volumio sudo[25982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:18 volumio sudo[25984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 20:11:18 volumio sudo[25984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:18 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:11:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:11:18 volumio sudo[25984]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:11:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:11:18 volumio systemd[1]: shairport-sync.service: Consumed 2.329s CPU time. Mar 04 20:11:18 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:11:18 volumio volumio[25723]: info: CoreCommandRouter::volumioGetState Mar 04 20:11:18 volumio volumio[25723]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:18 volumio volumio[25723]: info: Upmpdcli Daemon Started Mar 04 20:11:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:11:19 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:11:19 volumio sudo[25982]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:19 volumio sudo[25980]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:19 volumio sudo[25978]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:19 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:11:19 volumio volumio[25723]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:11:19 volumio volumio[25723]: info: Shairport-Sync Started Mar 04 20:11:19 volumio volumio[25723]: Error adding Membership: Error: addMembership EINVAL Mar 04 20:11:19 volumio volumio[25723]: info: Shairport-Sync Started Mar 04 20:11:19 volumio volumio[25723]: info: Shairport-Sync Started Mar 04 20:11:21 volumio volumio[25723]: info: go-librespot daemon successfully initialized Mar 04 20:11:21 volumio mpd[25918]: 2026-03-04T20:11:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 20:11:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 04 20:11:21 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 20:11:21 volumio sudo[25886]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:21 volumio sudo[25866]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:21 volumio volumio[25723]: info: Completed starting Core Plugins Mar 04 20:11:21 volumio volumio[25723]: info: ------------------------------------------- Mar 04 20:11:21 volumio volumio[25723]: info: ----- MyVolumio plugins startup ---- Mar 04 20:11:21 volumio volumio[25723]: info: ------------------------------------------- Mar 04 20:11:21 volumio volumio[25723]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 20:11:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:21 volumio go-librespot[26013]: go-librespot daemon starting... Mar 04 20:11:21 volumio go-librespot[26016]: time="2026-03-04T20:11:21+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:21 volumio go-librespot[26016]: time="2026-03-04T20:11:21+01:00" level=debug msg="app state loaded" Mar 04 20:11:21 volumio go-librespot[26016]: time="2026-03-04T20:11:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:21 volumio volumio[25723]: error: MPD error: The expression evaluated to a falsy value: Mar 04 20:11:21 volumio volumio[25723]: assert.ok(self.idling) Mar 04 20:11:21 volumio volumio[25723]: error: The expression evaluated to a falsy value: Mar 04 20:11:21 volumio volumio[25723]: assert.ok(self.idling) Mar 04 20:11:21 volumio volumio[25723]: error: updateQueue error: null Mar 04 20:11:21 volumio volumio[25723]: info: MPD running with PID25918 Mar 04 20:11:21 volumio volumio[25723]: ,establishing connection Mar 04 20:11:21 volumio volumio[25723]: error: updateQueue error: null Mar 04 20:11:21 volumio go-librespot[26016]: time="2026-03-04T20:11:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:21 volumio go-librespot[26016]: time="2026-03-04T20:11:21+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:21 volumio go-librespot[26016]: time="2026-03-04T20:11:21+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:21 volumio go-librespot[26016]: time="2026-03-04T20:11:21+01:00" level=info msg="zeroconf server listening on port 42117" Mar 04 20:11:22 volumio go-librespot[26016]: time="2026-03-04T20:11:22+01:00" level=debug msg="obtained new client token: AABjnygSc+TrbUpba9JYVjTQzMD6v+Qj8Z7JGfNiWr7jx8IqcskaJf4GFQQ5f3iHeCI7dckhrLwF4XxUXu/y/yqttgSJX5rU2Dy7RMBPd4HxRV+xDocbCTnRWNKDXGAKEEEEkCzhy40gCiegCvVfS64lL/i+8KRxl7oLN/vPy7tbkz8Vrpf5gEQMtjlOyCkUoFGGSKCiXqljnLbyRRz9DajE7CS0GRLJJQHuYq3F2cP81bMN5qPx+T0=" Mar 04 20:11:22 volumio go-librespot[26016]: time="2026-03-04T20:11:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:22 volumio go-librespot[26016]: time="2026-03-04T20:11:22+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:22 volumio go-librespot[26016]: time="2026-03-04T20:11:22+01:00" level=debug msg="completed challenge" Mar 04 20:11:22 volumio go-librespot[26016]: time="2026-03-04T20:11:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:24 volumio volumio[25723]: info: Initializing connection to go-librespot Websocket Mar 04 20:11:24 volumio volumio[25723]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:11:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 04 20:11:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:25 volumio go-librespot[26023]: go-librespot daemon starting... Mar 04 20:11:25 volumio go-librespot[26024]: time="2026-03-04T20:11:25+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:25 volumio go-librespot[26024]: time="2026-03-04T20:11:25+01:00" level=debug msg="app state loaded" Mar 04 20:11:25 volumio go-librespot[26024]: time="2026-03-04T20:11:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:25 volumio go-librespot[26024]: time="2026-03-04T20:11:25+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:25 volumio go-librespot[26024]: time="2026-03-04T20:11:25+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:25 volumio go-librespot[26024]: time="2026-03-04T20:11:25+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:25 volumio go-librespot[26024]: time="2026-03-04T20:11:25+01:00" level=info msg="zeroconf server listening on port 33595" Mar 04 20:11:25 volumio go-librespot[26024]: time="2026-03-04T20:11:25+01:00" level=debug msg="obtained new client token: AADUqQEe9AcnrFzk16m6nI4OmVVv6Xw5ApdwyNVLPLtSE61EkPx07K5atcD9e4MWvBKkU/18+KG4UD6dDBLwaZR59R/WU/LmZBjOwUERY133a2i88breG2ZMTXHuBHCix30/JEeVqKI3j9sME3yTeKctQ5LvFt4SqQwceJlTovi8iYWz6IgL9SlGaErlYQreQtvpKT5qsNJt9gblcAfoLtYEObmImasu2GHFA3+ydSDp+1HwYpxFyyHEIw==" Mar 04 20:11:26 volumio go-librespot[26024]: time="2026-03-04T20:11:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:26 volumio go-librespot[26024]: time="2026-03-04T20:11:26+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:26 volumio go-librespot[26024]: time="2026-03-04T20:11:26+01:00" level=debug msg="completed challenge" Mar 04 20:11:26 volumio go-librespot[26024]: time="2026-03-04T20:11:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:26 volumio volumio[25723]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 20:11:27 volumio volumio[25723]: info: Initializing connection to go-librespot Websocket Mar 04 20:11:27 volumio volumio[25723]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:11:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 04 20:11:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:29 volumio go-librespot[26046]: go-librespot daemon starting... Mar 04 20:11:29 volumio go-librespot[26047]: time="2026-03-04T20:11:29+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:29 volumio go-librespot[26047]: time="2026-03-04T20:11:29+01:00" level=debug msg="app state loaded" Mar 04 20:11:29 volumio go-librespot[26047]: time="2026-03-04T20:11:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:29 volumio go-librespot[26047]: time="2026-03-04T20:11:29+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:29 volumio go-librespot[26047]: time="2026-03-04T20:11:29+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:29 volumio go-librespot[26047]: time="2026-03-04T20:11:29+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:29 volumio go-librespot[26047]: time="2026-03-04T20:11:29+01:00" level=info msg="zeroconf server listening on port 40961" Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 20:11:29 volumio volumio[25723]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 20:11:29 volumio volumio[25723]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 20:11:29 volumio volumio[25723]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 20:11:29 volumio volumio[25723]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 20:11:29 volumio volumio[25723]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 20:11:29 volumio volumio[25723]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 20:11:29 volumio volumio[25723]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 20:11:29 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 20:11:30 volumio go-librespot[26047]: time="2026-03-04T20:11:30+01:00" level=debug msg="obtained new client token: AABt00k3s7cRC3RdvnNLOVD4/FKO8OObE9geHEXzE1lq4eSqVDKjs0sb4sS0H2OKM8otbM0+j7niA1fWSKGf84MN4qWWMydG+1qRbyjtx+ZfoyZMptcNWI5BFVxQMv3xCTVkYjxT/R3bNNpnlSfpVSZuklkpmBCWWRHQ8AzFN2ngQpmLzxVPEwopoJuSFmsfruqmK5xiBm73aEzkLVOiKjkVfVn9oBchpNc3uMpYIFWnJKLet6unyF0=" Mar 04 20:11:30 volumio go-librespot[26047]: time="2026-03-04T20:11:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:30 volumio go-librespot[26047]: time="2026-03-04T20:11:30+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:30 volumio go-librespot[26047]: time="2026-03-04T20:11:30+01:00" level=debug msg="completed challenge" Mar 04 20:11:30 volumio go-librespot[26047]: time="2026-03-04T20:11:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:31 volumio volumio[25723]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 20:11:31 volumio volumio[25723]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 20:11:31 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:31 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:31 volumio volumio[25723]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 20:11:31 volumio volumio[25723]: info: MyVolumio login type: Token Mar 04 20:11:31 volumio volumio[25723]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 20:11:31 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 20:11:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 04 20:11:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:33 volumio go-librespot[26054]: go-librespot daemon starting... Mar 04 20:11:33 volumio volumio[25723]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 20:11:33 volumio volumio[25723]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 20:11:33 volumio volumio[25723]: info: Streaming services startup Mar 04 20:11:33 volumio volumio[25723]: info: Starting Streaming Daemon Mar 04 20:11:33 volumio go-librespot[26055]: time="2026-03-04T20:11:33+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:33 volumio go-librespot[26055]: time="2026-03-04T20:11:33+01:00" level=debug msg="app state loaded" Mar 04 20:11:33 volumio go-librespot[26055]: time="2026-03-04T20:11:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:33 volumio sudo[26063]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:11:33 volumio volumio[25723]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 20:11:33 volumio sudo[26063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:33 volumio sudo[26063]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:33 volumio volumio[25723]: info: Initializing connection to go-librespot Websocket Mar 04 20:11:33 volumio volumio[25723]: error: Cannot start Volumio Streaming Daemon Mar 04 20:11:33 volumio volumio[25723]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:11:33 volumio volumio[25723]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:11:33 volumio go-librespot[26055]: time="2026-03-04T20:11:33+01:00" level=debug msg="new websocket client" Mar 04 20:11:33 volumio volumio[25723]: info: Connection to go-librespot Websocket established Mar 04 20:11:33 volumio go-librespot[26055]: time="2026-03-04T20:11:33+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:33 volumio go-librespot[26055]: time="2026-03-04T20:11:33+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:33 volumio go-librespot[26055]: time="2026-03-04T20:11:33+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:33 volumio go-librespot[26055]: time="2026-03-04T20:11:33+01:00" level=info msg="zeroconf server listening on port 35721" Mar 04 20:11:34 volumio go-librespot[26055]: time="2026-03-04T20:11:34+01:00" level=debug msg="obtained new client token: AAAPUSWmUN7WPB7IlieLrA5zNCZXOA0PfDEEiC5IYA0CnCC5n0fafju/UpvZkPlFvH5Q4xsKaGdnBqy63UvnN0HCfeFZ6/dwXWrZk7oB6AHTvPsf+8ySQ4xUBuzZcd69uF1dKbi8r2jy1iIcugH3ulFBj8++qkgjrNgUU9ZaqOXGQ6Gwclcw4JDS1F/OMy/ogWGcbxnOUXCn+YCTNcPOgARWXzhkGTFoVV9w0/lh/0xxHz8gIDk4Qp8=" Mar 04 20:11:34 volumio go-librespot[26055]: time="2026-03-04T20:11:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:34 volumio go-librespot[26055]: time="2026-03-04T20:11:34+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:34 volumio go-librespot[26055]: time="2026-03-04T20:11:34+01:00" level=debug msg="completed challenge" Mar 04 20:11:34 volumio go-librespot[26055]: time="2026-03-04T20:11:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:34 volumio volumio[25723]: info: Connection to go-librespot Websocket closed Mar 04 20:11:34 volumio volumio[25723]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 04 20:11:34 volumio volumio[25723]: info: MyVolumio token set successfully Mar 04 20:11:34 volumio volumio[25723]: info: MYVOLUMIO: Adding device Mar 04 20:11:34 volumio volumio[25723]: info: MYVOLUMIO: Evaluating Server Mar 04 20:11:35 volumio volumio[25723]: info: MyVolumio Plan changed: premium Mar 04 20:11:35 volumio volumio[25723]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Mar 04 20:11:35 volumio volumio[25723]: info: Removing browser output: myVolumio user plan is not superstar Mar 04 20:11:35 volumio volumio[25723]: info: Removing audio output: Mar 04 20:11:35 volumio volumio[25723]: info: MYVOLUMIO: Adding device Mar 04 20:11:35 volumio volumio[25723]: info: MYVOLUMIO: Evaluating Server Mar 04 20:11:35 volumio volumio[25723]: info: Remote config written successfully Mar 04 20:11:35 volumio volumio[25723]: info: Starting Tunnel 1 Mar 04 20:11:35 volumio volumio[25723]: info: Starting Tunnel Connection Checker Mar 04 20:11:35 volumio volumio[25723]: info: Completed starting MyVolumio Plugin Mar 04 20:11:35 volumio volumio[25723]: info: MYVolumio Device enabled Mar 04 20:11:35 volumio volumio[25723]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 04 20:11:35 volumio volumio[25723]: info: MyVolumio status changed Mar 04 20:11:35 volumio volumio[25723]: info: Streaming services startup Mar 04 20:11:35 volumio volumio[25723]: info: Starting Streaming Daemon Mar 04 20:11:35 volumio sudo[26124]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:11:35 volumio sudo[26124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:35 volumio volumio[25723]: info: Setting Geolocation for MyVolumio to eu8 Mar 04 20:11:35 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:35 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:35 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:35 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 04 20:11:35 volumio sudo[26124]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:35 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 04 20:11:36 volumio volumio[25723]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Mar 04 20:11:36 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 04 20:11:36 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:36.340+01:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.178.147:46046 @ 0x28a2390" latency=57.560816ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Mar 04 20:11:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 04 20:11:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:37 volumio go-librespot[26126]: go-librespot daemon starting... Mar 04 20:11:37 volumio go-librespot[26127]: time="2026-03-04T20:11:37+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:37 volumio go-librespot[26127]: time="2026-03-04T20:11:37+01:00" level=debug msg="app state loaded" Mar 04 20:11:37 volumio go-librespot[26127]: time="2026-03-04T20:11:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:37 volumio go-librespot[26127]: time="2026-03-04T20:11:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:37 volumio go-librespot[26127]: time="2026-03-04T20:11:37+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:37 volumio go-librespot[26127]: time="2026-03-04T20:11:37+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:37 volumio go-librespot[26127]: time="2026-03-04T20:11:37+01:00" level=info msg="zeroconf server listening on port 46049" Mar 04 20:11:38 volumio go-librespot[26127]: time="2026-03-04T20:11:38+01:00" level=debug msg="obtained new client token: AAB7JukeBN04rzHLSh1U/pyEcGui3glehi0V5X9NNV9PRIdGJPtRO1gwzk+eqACQNEgW8Rt4dxfgtd+OzJZIa4r/mUfG6NuoGwkezY3C0D4c14+IirCnrk1F+Y29il8Ulx6WQUG34glTRjVSo6G+qJ4BT3oiRz64nmcmYEJ9v0M4ANvYz8CpoKLVwhMfKasK/tTBHlHpDhP3wjku41irBCUVwACpCgvpexJ+9uI6rfaEEZMecXTrWqo=" Mar 04 20:11:38 volumio go-librespot[26127]: time="2026-03-04T20:11:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:38 volumio go-librespot[26127]: time="2026-03-04T20:11:38+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:38 volumio go-librespot[26127]: time="2026-03-04T20:11:38+01:00" level=debug msg="completed challenge" Mar 04 20:11:38 volumio go-librespot[26127]: time="2026-03-04T20:11:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:38 volumio volumio[25723]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 04 20:11:38 volumio sudo[26136]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 04 20:11:38 volumio sudo[26136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:38 volumio sudo[26136]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:38 volumio volumio[25723]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Mar 04 20:11:38 volumio volumio[25723]: info: MRS: MultiRoom plugin initialized Mar 04 20:11:38 volumio volumio[25723]: info: MRS: STOPPING SNAPCLIENT Mar 04 20:11:38 volumio volumio[25723]: info: MRS: Snap server stop Mar 04 20:11:38 volumio volumio[25723]: info: MRS: STOPPING volumioStreaming Mar 04 20:11:38 volumio sudo[26153]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 04 20:11:38 volumio sudo[26153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:38 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 04 20:11:38 volumio sudo[26155]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 04 20:11:38 volumio sudo[26155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:38 volumio sudo[26157]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 04 20:11:38 volumio sudo[26157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:38 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 04 20:11:38 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 04 20:11:38 volumio sudo[26160]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 04 20:11:38 volumio sudo[26160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:38 volumio sudo[26160]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:38 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 04 20:11:39 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 04 20:11:39 volumio volumio[25723]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 04 20:11:39 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 04 20:11:39 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 04 20:11:39 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 04 20:11:39 volumio sudo[26153]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:39 volumio volumio[25723]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Mar 04 20:11:39 volumio sudo[26157]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:39 volumio volumio[25723]: info: Preparing to generate the ALSA configuration file Mar 04 20:11:39 volumio sudo[26155]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:39 volumio volumio[25723]: info: Getting Spotify volume Mar 04 20:11:39 volumio volumio[25723]: info: Initializing connection to go-librespot Websocket Mar 04 20:11:39 volumio volumio[25723]: info: Updating MyVolumio device info Mar 04 20:11:39 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:39 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:39 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:39 volumio volumio[25723]: info: Setting Geolocation for MyVolumio to eu2 Mar 04 20:11:39 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:39 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:39 volumio volumio[25723]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:39 volumio volumio[25723]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 04 20:11:39 volumio volumio[25723]: info: Reading ALSA contributions from plugins. Mar 04 20:11:39 volumio volumio[25723]: info: Successfully Added MyVolumio device Mar 04 20:11:39 volumio volumio[25723]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:11:39 volumio volumio[25723]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:11:39 volumio volumio[25723]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 04 20:11:39 volumio volumio[25723]: errno: -111, Mar 04 20:11:39 volumio volumio[25723]: code: 'ECONNREFUSED', Mar 04 20:11:39 volumio volumio[25723]: syscall: 'connect', Mar 04 20:11:39 volumio volumio[25723]: address: '127.0.0.1', Mar 04 20:11:39 volumio volumio[25723]: port: 9879, Mar 04 20:11:39 volumio volumio[25723]: response: undefined Mar 04 20:11:39 volumio volumio[25723]: } Mar 04 20:11:39 volumio volumio[25723]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:11:40 volumio sudo[26178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 20:10' Mar 04 20:11:40 volumio sudo[26178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:41 volumio sudo[26178]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 04 20:11:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:41 volumio go-librespot[26183]: go-librespot daemon starting... Mar 04 20:11:41 volumio go-librespot[26186]: time="2026-03-04T20:11:41+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:41 volumio go-librespot[26186]: time="2026-03-04T20:11:41+01:00" level=debug msg="app state loaded" Mar 04 20:11:41 volumio go-librespot[26186]: time="2026-03-04T20:11:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:41 volumio volumio-remote-updater[708]: [2026-03-04 20:11:41] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 04 20:11:41 volumio volumio-remote-updater[708]: [2026-03-04 20:11:41] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 04 20:11:41 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:41.507+01:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Mar 04 20:11:41 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:41.512+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:48468->127.0.0.1:3000: read: connection reset by peer" Mar 04 20:11:41 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:41 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 04 20:11:41 volumio systemd[1]: volumio.service: Consumed 52.342s CPU time. Mar 04 20:11:41 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 20:11:41 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 20:11:41 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 33. Mar 04 20:11:41 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 20:11:41 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 04 20:11:41 volumio systemd[1]: volumio.service: Consumed 52.342s CPU time. Mar 04 20:11:41 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 04 20:11:41 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 20:11:41 volumio go-librespot[26186]: time="2026-03-04T20:11:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:41 volumio go-librespot[26186]: time="2026-03-04T20:11:41+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:41 volumio go-librespot[26186]: time="2026-03-04T20:11:41+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:41 volumio go-librespot[26186]: time="2026-03-04T20:11:41+01:00" level=info msg="zeroconf server listening on port 36425" Mar 04 20:11:42 volumio go-librespot[26186]: time="2026-03-04T20:11:42+01:00" level=debug msg="obtained new client token: AABH3HbigFGzgmB0zjS0z3sRTajkmsXWk4nWimJicQ8tpOJdxHAoY1FP5T4SDCGpJlNbJZJttJf87zU0j63Bnth8C/uA+hDvylb6m+2atNbT73lHW/0ZGptRsytMMVP6haV76O/g2oCZdrJ4Qvqrww55c6uy69tZMAqLu9jNvlBw1fc7hje5bjZ3dzoDvfbu+HvxFK+TIIDGUGDG6nweUVNCTZkVSniOh3H294zWl9h8UY0H41nQY/s=" Mar 04 20:11:42 volumio go-librespot[26186]: time="2026-03-04T20:11:42+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 20:11:42 volumio go-librespot[26186]: time="2026-03-04T20:11:42+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 20:11:42 volumio go-librespot[26186]: time="2026-03-04T20:11:42+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:42 volumio go-librespot[26186]: time="2026-03-04T20:11:42+01:00" level=debug msg="completed challenge" Mar 04 20:11:42 volumio go-librespot[26186]: time="2026-03-04T20:11:42+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:42 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:42.514+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 20:11:43 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:43.499+01:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.178.147:46046 @ 0x28a2390" latency=24.762136ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Mar 04 20:11:43 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:43.516+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 20:11:45 volumio volumio[26209]: info: ------------------------------------------- Mar 04 20:11:45 volumio volumio[26209]: info: ----- Volumio3 ---- Mar 04 20:11:45 volumio volumio[26209]: info: ------------------------------------------- Mar 04 20:11:45 volumio volumio[26209]: info: ----- System startup ---- Mar 04 20:11:45 volumio volumio[26209]: info: ------------------------------------------- Mar 04 20:11:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Mar 04 20:11:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:45 volumio go-librespot[26231]: go-librespot daemon starting... Mar 04 20:11:45 volumio go-librespot[26232]: time="2026-03-04T20:11:45+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:45 volumio go-librespot[26232]: time="2026-03-04T20:11:45+01:00" level=debug msg="app state loaded" Mar 04 20:11:45 volumio go-librespot[26232]: time="2026-03-04T20:11:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:46 volumio go-librespot[26232]: time="2026-03-04T20:11:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:46 volumio go-librespot[26232]: time="2026-03-04T20:11:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:46 volumio go-librespot[26232]: time="2026-03-04T20:11:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:46 volumio go-librespot[26232]: time="2026-03-04T20:11:46+01:00" level=info msg="zeroconf server listening on port 44549" Mar 04 20:11:46 volumio go-librespot[26232]: time="2026-03-04T20:11:46+01:00" level=debug msg="obtained new client token: AACVIrbPBLWJDvHFTR/qETeCycbY8s9940VRL3IQ+s+P4Mu7i8YSsTlHeuCDZvFSXVm6qSOJj1ZOPNrLNFJfWrQhZ6bP1jwS6I5l/RmQKOsxhkYl0x67UuZofnxaObhHPAbMX3OP6cSmkhVmyXkoVT7OG5X3/a1Zq/w9nuHDVSeL/ZIG37LxidWboZeJNtyJ7WVXDnAJGO5fH6KpyrU5oFXDqTRTaqC4zcj6guCP5y2XIANL75u96/E=" Mar 04 20:11:46 volumio go-librespot[26232]: time="2026-03-04T20:11:46+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:46 volumio go-librespot[26232]: time="2026-03-04T20:11:46+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:46 volumio go-librespot[26232]: time="2026-03-04T20:11:46+01:00" level=debug msg="completed challenge" Mar 04 20:11:46 volumio go-librespot[26232]: time="2026-03-04T20:11:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:46 volumio volumio-remote-updater[708]: [2026-03-04 20:11:46] [connect] Successful connection Mar 04 20:11:46 volumio volumio[26209]: info: MYVOLUMIO Environment detected Mar 04 20:11:46 volumio volumio[26209]: info: Plugin folders cleanup Mar 04 20:11:46 volumio volumio[26209]: info: Scanning into folder /volumio/app/plugins/ Mar 04 20:11:46 volumio volumio[26209]: info: Scanning category audio_interface Mar 04 20:11:46 volumio volumio[26209]: info: Scanning category miscellanea Mar 04 20:11:46 volumio volumio[26209]: info: Scanning category music_service Mar 04 20:11:46 volumio volumio[26209]: info: Scanning category plugins.json Mar 04 20:11:46 volumio volumio[26209]: info: Scanning category system_controller Mar 04 20:11:46 volumio volumio[26209]: info: Scanning category user_interface Mar 04 20:11:46 volumio volumio[26209]: info: Scanning into folder /data/plugins/ Mar 04 20:11:46 volumio volumio[26209]: info: Scanning category music_service Mar 04 20:11:46 volumio volumio[26209]: info: Plugin folders cleanup completed Mar 04 20:11:46 volumio volumio[26209]: info: ------------------------------------------- Mar 04 20:11:46 volumio volumio[26209]: info: ----- Core plugins startup ---- Mar 04 20:11:46 volumio volumio[26209]: info: ------------------------------------------- Mar 04 20:11:46 volumio volumio[26209]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 20:11:46 volumio volumio[26209]: info: Adding plugin upnp to MyMusic Plugins Mar 04 20:11:46 volumio volumio[26209]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 20:11:46 volumio volumio[26209]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 20:11:46 volumio volumio[26209]: info: Loading plugins from folder /data/plugins/ Mar 04 20:11:46 volumio volumio[26209]: info: Loading plugin "system"... Mar 04 20:11:46 volumio volumio[26209]: info: Loading plugin "appearance"... Mar 04 20:11:48 volumio volumio[26209]: info: Loading plugin "network"... Mar 04 20:11:48 volumio volumio[26209]: info: Refreshing Cached IP Addresses Mar 04 20:11:48 volumio sudo[26248]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:11:48 volumio sudo[26248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:48 volumio sudo[26250]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:11:48 volumio sudo[26250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:48 volumio volumio[26209]: info: Loading plugin "services"... Mar 04 20:11:48 volumio sudo[26248]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:48 volumio volumio[26209]: info: Loading plugin "volumio5onboarding"... Mar 04 20:11:48 volumio sudo[26250]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:48 volumio sudo[26257]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 20:11:48 volumio volumio[26209]: info: Loading plugin "alsa_controller"... Mar 04 20:11:48 volumio sudo[26257]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:48 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:11:48 volumio volumio[26209]: info: Loading plugin "wizard"... Mar 04 20:11:48 volumio volumio[26209]: info: Loading plugin "networkfs"... Mar 04 20:11:49 volumio volumio[26209]: info: Starting Udev Watcher for removable devices Mar 04 20:11:49 volumio volumio[26209]: info: Ignoring mount for partition: boot Mar 04 20:11:49 volumio volumio[26209]: info: Ignoring mount for partition: volumio Mar 04 20:11:49 volumio volumio[26209]: info: Ignoring mount for partition: volumio_data Mar 04 20:11:49 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:11:49 volumio volumio[26209]: info: Loading plugin "volumio_command_line_client"... Mar 04 20:11:49 volumio volumio[26209]: info: Loading plugin "upnp"... Mar 04 20:11:49 volumio volumio[26209]: info: [1772651509123] Starting Upmpd Daemon Mar 04 20:11:49 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:11:49 volumio volumio[26209]: info: Loading plugin "my_music"... Mar 04 20:11:49 volumio volumio[26209]: info: Loading plugin "mpd"... Mar 04 20:11:49 volumio sudo[26257]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Mar 04 20:11:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:49 volumio go-librespot[26281]: go-librespot daemon starting... Mar 04 20:11:49 volumio go-librespot[26282]: time="2026-03-04T20:11:49+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:49 volumio go-librespot[26282]: time="2026-03-04T20:11:49+01:00" level=debug msg="app state loaded" Mar 04 20:11:49 volumio go-librespot[26282]: time="2026-03-04T20:11:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:49 volumio volumio[26209]: info: Loading plugin "upnp_browser"... Mar 04 20:11:49 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:49.941+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.178.147:46046 @ 0x28a2390" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 04 20:11:50 volumio go-librespot[26282]: time="2026-03-04T20:11:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 20:11:50 volumio go-librespot[26282]: time="2026-03-04T20:11:50+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 20:11:50 volumio go-librespot[26282]: time="2026-03-04T20:11:50+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 20:11:50 volumio go-librespot[26282]: time="2026-03-04T20:11:50+01:00" level=info msg="zeroconf server listening on port 46325" Mar 04 20:11:50 volumio go-librespot[26282]: time="2026-03-04T20:11:50+01:00" level=debug msg="obtained new client token: AAASUSZ4Q3sE1MtbkU2sDTevzzFckzXzkJZifE57T91ldUDZ0EkS9Z2xvG7l0NjtWW8RxpXw3fT9JnCNXpvDqAs0FL31lG12AiriKj5fiQuW1wOp4D8zGinGZvvbCPBheDqtHsJZC3Nv9/AAHW93rTXSRravZUYvQ9ye5jtqYHhwh8hYFVwyheMXT9qeLBaZNIDzTq4fQV4Fj1mhD9A9LbTnSJ8dVHZi3gQKj652jucHx+o9aH2OwUHLsQ==" Mar 04 20:11:50 volumio go-librespot[26282]: time="2026-03-04T20:11:50+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:50 volumio go-librespot[26282]: time="2026-03-04T20:11:50+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:50 volumio go-librespot[26282]: time="2026-03-04T20:11:50+01:00" level=debug msg="completed challenge" Mar 04 20:11:50 volumio go-librespot[26282]: time="2026-03-04T20:11:50+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:52 volumio volumio[26209]: info: Starting UPNP Browser Mar 04 20:11:52 volumio volumio[26209]: info: Loading plugin "alarm-clock"... Mar 04 20:11:52 volumio volumio[26209]: info: Loading plugin "airplay_emulation"... Mar 04 20:11:53 volumio volumio[26209]: info: Starting Shairport Sync Mar 04 20:11:53 volumio volumio[26209]: info: Loading plugin "last_100"... Mar 04 20:11:53 volumio volumio[26209]: info: Loading plugin "webradio"... Mar 04 20:11:53 volumio volumio[26209]: info: Loading plugin "i2s_dacs"... Mar 04 20:11:53 volumio volumio[26209]: info: Loading plugin "volumiodiscovery"... Mar 04 20:11:53 volumio volumio[26209]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:11:53 volumio volumio[26209]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:11:53 volumio volumio[26209]: *** WARNING *** For more information see Mar 04 20:11:53 volumio volumio[26209]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:11:53 volumio volumio[26209]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:11:53 volumio node[26209]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:11:53 volumio volumio[26209]: *** WARNING *** For more information see Mar 04 20:11:53 volumio node[26209]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:11:53 volumio node[26209]: *** WARNING *** For more information see Mar 04 20:11:53 volumio node[26209]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:11:53 volumio node[26209]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:11:53 volumio node[26209]: *** WARNING *** For more information see Mar 04 20:11:53 volumio volumio[26209]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 20:11:53 volumio volumio[26209]: info: Discovery: Started advertising with name: Volumio Mar 04 20:11:53 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:11:53 volumio volumio[26209]: info: Loading plugin "spop"... Mar 04 20:11:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Mar 04 20:11:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:53 volumio go-librespot[26292]: go-librespot daemon starting... Mar 04 20:11:53 volumio go-librespot[26293]: time="2026-03-04T20:11:53+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:53 volumio go-librespot[26293]: time="2026-03-04T20:11:53+01:00" level=debug msg="app state loaded" Mar 04 20:11:53 volumio go-librespot[26293]: time="2026-03-04T20:11:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:54 volumio go-librespot[26293]: time="2026-03-04T20:11:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:11:54 volumio go-librespot[26293]: time="2026-03-04T20:11:54+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:11:54 volumio go-librespot[26293]: time="2026-03-04T20:11:54+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:11:54 volumio go-librespot[26293]: time="2026-03-04T20:11:54+01:00" level=info msg="zeroconf server listening on port 36691" Mar 04 20:11:54 volumio go-librespot[26293]: time="2026-03-04T20:11:54+01:00" level=debug msg="obtained new client token: AAAdyWPOkLcilnIaOpiQbcSOYUTwzuUtAOlnivnsp1q87nxbxJF9HevgwERwcC6HyhzzH4TMQz8yGpa43Lz9ae6tbLuzcMQ4ebXNzeYmjOnn/ztnqTC4V01qSoSc2hooZNJQEe8ZkfmnjhrewSuyzNFCB5AYzJw7J/FS/Smc6O+bLwnXh9XVviUo7EK2Da+JQ7FzeqmfOk3jLB0mRTDBBVmDoiFQb/iVi7RPKiwabro0NjkEJUcCO+HXTQ==" Mar 04 20:11:54 volumio go-librespot[26293]: time="2026-03-04T20:11:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:54 volumio go-librespot[26293]: time="2026-03-04T20:11:54+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:54 volumio go-librespot[26293]: time="2026-03-04T20:11:54+01:00" level=debug msg="completed challenge" Mar 04 20:11:54 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:54.519+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:48490->127.0.0.1:3000: i/o timeout" Mar 04 20:11:54 volumio go-librespot[26293]: time="2026-03-04T20:11:54+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:55 volumio volumio[26209]: info: Loading plugin "outputs"... Mar 04 20:11:55 volumio volumio[26209]: info: Loading plugin "albumart"... Mar 04 20:11:55 volumio volumio[26209]: info: Plugin example_plugin is not enabled Mar 04 20:11:55 volumio volumio[26209]: info: Loading plugin "inputs"... Mar 04 20:11:55 volumio volumio[26209]: info: Loading plugin "updater_comm"... Mar 04 20:11:55 volumio volumio[26209]: info: Plugin mpdemulation is not enabled Mar 04 20:11:55 volumio volumio[26209]: info: Loading plugin "rest_api"... Mar 04 20:11:55 volumio volumio[26209]: info: Loading plugin "websocket"... Mar 04 20:11:55 volumio volumio[26209]: info: Starting Socket.io Server version 1.7.4 Mar 04 20:11:55 volumio volumio[26209]: info: Loading i18n strings for locale nl Mar 04 20:11:55 volumio volumio[26209]: Updating browse sources language Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::initPlayerControls Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:11:55 volumio volumio[26209]: Express server listening on port 3000 Mar 04 20:11:55 volumio volumio[26209]: [Metrics] WebUI: 11s 718.78ms Mar 04 20:11:55 volumio volumio[26209]: info: CoreStateMachine::resetVolumioState Mar 04 20:11:55 volumio volumio[26209]: info: CoreStateMachine::getcurrentVolume Mar 04 20:11:55 volumio volumio[26209]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:11:56 volumio volumio[26209]: info: Volumio Network Manager: Network status updated: 1 Mar 04 20:11:56 volumio volumio[26300]: Forking 3 albumart workers Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:56 volumio volumio[26209]: info: Reloading queue from file Mar 04 20:11:56 volumio volumio[26209]: info: VolumeController:: Volume=5 Mute =false Mar 04 20:11:56 volumio volumio[26209]: info: CoreStateMachine::pushState Mar 04 20:11:56 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::volumioPushState Mar 04 20:11:56 volumio volumio[26209]: info: CoreStateMachine::updateTrackBlock Mar 04 20:11:56 volumio volumio[26209]: info: CorePlayQueue::getTrackBlock Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:11:56 volumio volumio[26209]: info: CoreStateMachine::setRepeat false single undefined Mar 04 20:11:56 volumio volumio[26209]: info: CoreStateMachine::pushState Mar 04 20:11:56 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::volumioPushState Mar 04 20:11:56 volumio volumio[26209]: info: CoreStateMachine::setRandom undefined Mar 04 20:11:56 volumio volumio[26209]: info: CoreStateMachine::pushState Mar 04 20:11:56 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::volumioPushState Mar 04 20:11:56 volumio volumio[26209]: info: Setting Device type: Raspberry PI Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:11:56 volumio volumio[26209]: info: Discovery: Getting this device information Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::volumioGetState Mar 04 20:11:56 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:11:56 volumio volumio[26209]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 20:11:56 volumio volumio[26209]: info: Completed loading Core Plugins Mar 04 20:11:56 volumio volumio[26209]: info: Preparing to generate the ALSA configuration file Mar 04 20:11:56 volumio volumio[26209]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 20:11:56 volumio volumio[26209]: info: Received Get System Info Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:11:56 volumio volumio[26209]: info: Discovery: Getting this device information Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::volumioGetState Mar 04 20:11:56 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 20:11:56 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 20:11:57 volumio volumio[26209]: verbose: New Socket.io Connection to 192.168.178.145:3000 from 192.168.178.147 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 2 Mar 04 20:11:57 volumio volumio[26209]: info: VolumeController:: Volume=5 Mute =false Mar 04 20:11:57 volumio volumio[26209]: info: CoreStateMachine::pushState Mar 04 20:11:57 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::volumioPushState Mar 04 20:11:57 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:57.051+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:46046 @ 0x28a2390" state=STATUS_STOPPED positionMs=0 volume=5 Mar 04 20:11:57 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:57.052+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:46046 @ 0x28a2390" id=tidal://song/279755622 title="La Vida Breve: Danza Española Nr. 1" Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 20:11:57 volumio volumio[26209]: info: Asound.conf file unchanged, so no further update is needed Mar 04 20:11:57 volumio volumio[26209]: info: Output device has changed, restarting MPD Mar 04 20:11:57 volumio volumio[26209]: info: Output device has changed, restarting Shairport Sync Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:57 volumio sudo[26354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:11:57 volumio sudo[26354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:57 volumio sudo[26354]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:57 volumio volumio[26209]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:11:57 volumio volumio[26209]: info: ___________ START PLUGINS ___________ Mar 04 20:11:57 volumio sudo[26356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:11:57 volumio sudo[26356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:57 volumio volumio[26209]: info: ControllerMpd::onStart: Initializing MPD Mar 04 20:11:57 volumio volumio[26209]: info: Creating MPD Configuration file Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:11:57 volumio sudo[26364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:11:57 volumio volumio[26209]: info: [1772651517317] CoreMusicLibrary::Adding element Media Servers Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:11:57 volumio sudo[26364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:57 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 20:11:57 volumio volumio[26209]: info: UPNP Browser: Client initialized successfully Mar 04 20:11:57 volumio sudo[26366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:11:57 volumio sudo[26368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:11:57 volumio sudo[26366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:57 volumio sudo[26368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:57 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:11:57 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:11:57 volumio systemd[1]: mpd.service: Consumed 6.791s CPU time. Mar 04 20:11:57 volumio sudo[26366]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:57 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:57 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:11:57 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:11:57 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:11:57 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:11:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Mar 04 20:11:57 volumio volumio[26209]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:11:57 volumio go-librespot[26383]: go-librespot daemon starting... Mar 04 20:11:57 volumio sudo[26364]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:57 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:11:57 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:11:57 volumio volumio[26209]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:11:57 volumio volumio[26209]: info: [1772651517736] CoreMusicLibrary::Adding element Last_100 Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:11:57 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:11:57 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:11:57 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:11:57 volumio volumio[26209]: info: [1772651517762] CoreMusicLibrary::Adding element Webradio Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:11:57 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:11:57 volumio volumio[26209]: info: Initializing BBC Radios Mar 04 20:11:57 volumio go-librespot[26384]: time="2026-03-04T20:11:57+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:11:57 volumio go-librespot[26384]: time="2026-03-04T20:11:57+01:00" level=debug msg="app state loaded" Mar 04 20:11:57 volumio go-librespot[26384]: time="2026-03-04T20:11:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:11:57 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:11:57 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:11:58 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:11:58 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:11:58 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:58.095+01:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.178.147:46046 Mar 04 20:11:58 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:58.098+01:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.178.147:46046 Mar 04 20:11:58 volumio volumio5-onboarding[2437]: time=2026-03-04T20:11:58.100+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.178.147:56938 Mar 04 20:11:58 volumio volumio[26209]: info: Creating Spotify config file Mar 04 20:11:58 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:11:58 volumio sudo[26394]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 20:11:58 volumio sudo[26394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 20:11:58 volumio sudo[26394]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:58 volumio go-librespot[26384]: time="2026-03-04T20:11:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 20:11:58 volumio go-librespot[26384]: time="2026-03-04T20:11:58+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 20:11:58 volumio go-librespot[26384]: time="2026-03-04T20:11:58+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 20:11:58 volumio go-librespot[26384]: time="2026-03-04T20:11:58+01:00" level=info msg="zeroconf server listening on port 45787" Mar 04 20:11:58 volumio go-librespot[26384]: time="2026-03-04T20:11:58+01:00" level=debug msg="obtained new client token: AABSDCp7oP3ogeOSldbKe+sMVN0FALnKgehgZgBLGJWET1Heqq28zYMKUb6FC/iEhSlH8teDzvLKvH1gTcI0aM7UivfNNWkyrfZOfdBbm6GdterGB8HOJ+U7SesJU5+FcSfy7QreaRSTclJnhvPCI0Zf5O9FcxeR6ttIAtGZB7YNT05AkulONxagQciX8M/0RHRtmOH6YlH2JETyxedBVbLX8DECNetUAYTBruuyyYWn5XXHzmalpi9FNA==" Mar 04 20:11:58 volumio go-librespot[26384]: time="2026-03-04T20:11:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:11:58 volumio go-librespot[26384]: time="2026-03-04T20:11:58+01:00" level=debug msg="completed keyexchange" Mar 04 20:11:58 volumio go-librespot[26384]: time="2026-03-04T20:11:58+01:00" level=debug msg="completed challenge" Mar 04 20:11:58 volumio go-librespot[26384]: time="2026-03-04T20:11:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:11:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:11:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:11:59 volumio volumio-remote-updater[708]: [2026-03-04 20:11:59] [connect] Successful connection Mar 04 20:11:59 volumio volumio[26209]: info: Volumio Calling Home Mar 04 20:11:59 volumio volumio[26209]: info: Discovery: adding 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 20:11:59 volumio volumio[26209]: info: Discovery: Found device Volumio Mar 04 20:11:59 volumio volumio[26209]: info: CoreCommandRouter::volumioGetState Mar 04 20:11:59 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:59 volumio volumio[26316]: Starting albumart workers Mar 04 20:11:59 volumio volumio[26209]: info: Discovery: this is already registered, 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 20:11:59 volumio volumio[26209]: info: Discovery: Found device Volumio Mar 04 20:11:59 volumio volumio[26209]: info: CoreCommandRouter::volumioGetState Mar 04 20:11:59 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:11:59 volumio sudo[26430]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:11:59 volumio sudo[26430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:11:59 volumio sudo[26430]: pam_unix(sudo:session): session closed for user root Mar 04 20:11:59 volumio volumio[26209]: info: MPD Permissions set Mar 04 20:11:59 volumio volumio[26209]: info: MPD Permissions set Mar 04 20:11:59 volumio sudo[26432]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:11:59 volumio sudo[26432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:00 volumio sudo[26432]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:00 volumio volumio-remote-updater[708]: [2026-03-04 20:12:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772651518 101 Mar 04 20:12:00 volumio volumio[26209]: 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: 2 Mar 04 20:12:00 volumio volumio[26209]: info: Volumio called home Mar 04 20:12:00 volumio volumio[26209]: info: Spotify config file written Mar 04 20:12:00 volumio volumio[26315]: Starting albumart workers Mar 04 20:12:00 volumio sudo[26436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 20:12:00 volumio sudo[26436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:00 volumio go-librespot[26438]: go-librespot daemon starting... Mar 04 20:12:00 volumio sudo[26436]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:00 volumio go-librespot[26439]: time="2026-03-04T20:12:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:00 volumio go-librespot[26439]: time="2026-03-04T20:12:00+01:00" level=debug msg="app state loaded" Mar 04 20:12:00 volumio go-librespot[26439]: time="2026-03-04T20:12:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:00 volumio volumio[26209]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 04 20:12:00 volumio volumio[26317]: Starting albumart workers Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:00 volumio volumio[26209]: info: No need to fix Spotify hosts Mar 04 20:12:01 volumio go-librespot[26439]: time="2026-03-04T20:12:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:01 volumio go-librespot[26439]: time="2026-03-04T20:12:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:01 volumio go-librespot[26439]: time="2026-03-04T20:12:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:01 volumio go-librespot[26439]: time="2026-03-04T20:12:01+01:00" level=info msg="zeroconf server listening on port 46171" Mar 04 20:12:01 volumio go-librespot[26439]: time="2026-03-04T20:12:01+01:00" level=debug msg="obtained new client token: AAAcYNilqo5DktF33IDOgJDzhPmen94fyI7edZ7+kv71M1GqT2GZekbJhI3l/fjwATKaI/scyeCimm3Nb35tzoFd8t8BpTR58lKBODfBJBenBMSfHQIuchCrn/QZ7Xq4Kfec0a0WgAOEQiNLJNrwpT7fwymiFbuDQF6MPjMmQmNCazRjwfBDg5iEFfiz1cPJh+CHejVnJFWNi75BuMNm3QXi6kvpZc/HAZvO9LJ3vFGUZVJTTFu5rknLhQ==" Mar 04 20:12:01 volumio volumio5-onboarding[2437]: time=2026-03-04T20:12:01.493+01:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.178.147:56938 @ 0x24a6720" latency=24.639875ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Mar 04 20:12:01 volumio go-librespot[26439]: time="2026-03-04T20:12:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:01 volumio volumio[26209]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 04 20:12:01 volumio go-librespot[26439]: time="2026-03-04T20:12:01+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:01 volumio go-librespot[26439]: time="2026-03-04T20:12:01+01:00" level=debug msg="completed challenge" Mar 04 20:12:01 volumio volumio[26209]: info: Starting Shairport Sync Mar 04 20:12:01 volumio go-librespot[26439]: time="2026-03-04T20:12:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:01 volumio volumio[26209]: info: Starting Shairport Sync Mar 04 20:12:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:01 volumio volumio[26209]: info: Starting Shairport Sync Mar 04 20:12:01 volumio sudo[26459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:12:01 volumio sudo[26463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:12:01 volumio sudo[26463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:01 volumio sudo[26459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:01 volumio sudo[26468]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:12:01 volumio sudo[26468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:01 volumio sudo[26472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 20:12:01 volumio sudo[26472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:12:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:12:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:12:02 volumio systemd[1]: shairport-sync.service: Consumed 2.328s CPU time. Mar 04 20:12:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:12:02 volumio sudo[26468]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:02 volumio volumio[26209]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:02 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:02 volumio sudo[26463]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:02 volumio sudo[26459]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:02 volumio volumio[26209]: info: Shairport-Sync Started Mar 04 20:12:02 volumio sudo[26472]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:02 volumio volumio[26209]: Error adding Membership: Error: addMembership EINVAL Mar 04 20:12:02 volumio volumio[26209]: info: Upmpdcli Daemon Started Mar 04 20:12:02 volumio volumio[26209]: info: Shairport-Sync Started Mar 04 20:12:02 volumio volumio[26209]: info: Shairport-Sync Started Mar 04 20:12:03 volumio sudo[26503]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:12:03 volumio sudo[26503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:03 volumio sudo[26505]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:12:03 volumio sudo[26505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:03 volumio sudo[26503]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:03 volumio sudo[26505]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:03 volumio volumio[26209]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Mar 04 20:12:03 volumio sudo[26510]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:12:03 volumio sudo[26510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:03 volumio sudo[26511]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:12:03 volumio sudo[26510]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:03 volumio sudo[26511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:03 volumio sudo[26511]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:03 volumio volumio[26209]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:03 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 04 20:12:03 volumio volumio[26209]: info: Received Get System Info Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:12:03 volumio volumio[26209]: info: Discovery: Getting this device information Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:03 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:03 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:03 volumio volumio[26209]: info: Listing playlists Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 04 20:12:03 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 04 20:12:04 volumio volumio[26209]: info: go-librespot daemon successfully initialized Mar 04 20:12:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Mar 04 20:12:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:04 volumio go-librespot[26514]: go-librespot daemon starting... Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=debug msg="app state loaded" Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:05 volumio mpd[26409]: 2026-03-04T20:12:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 20:12:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 20:12:05 volumio sudo[26368]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:05 volumio sudo[26356]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:05 volumio volumio[26209]: info: Completed starting Core Plugins Mar 04 20:12:05 volumio volumio[26209]: info: ------------------------------------------- Mar 04 20:12:05 volumio volumio[26209]: info: ----- MyVolumio plugins startup ---- Mar 04 20:12:05 volumio volumio[26209]: info: ------------------------------------------- Mar 04 20:12:05 volumio volumio[26209]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=info msg="zeroconf server listening on port 34103" Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=debug msg="obtained new client token: AACs+gf91g/q7r2uRgNyFzSwEZrvdMiNu42UjUyNK8bG7O2vwZ/ZiXni6dJdv1Rg8BKtRTfjEFrexM281tK1YKfsSQZX/ETEwilskTYexgzlQWaQQU0yABrqpkCL6ie03bXrTw5jOg6UQ4P6MMFxU5brPRkTFda6S/HLAVWlTE5QDZhtBKLjaRqgqYYwzA2b/1ptDh4FzMqomBnpZUGH2zpwXNx0Bal1Ad/5SA/Ue0E3Ol034IabZqc+bQ==" Mar 04 20:12:05 volumio volumio[26209]: error: MPD error: The expression evaluated to a falsy value: Mar 04 20:12:05 volumio volumio[26209]: assert.ok(self.idling) Mar 04 20:12:05 volumio volumio[26209]: error: The expression evaluated to a falsy value: Mar 04 20:12:05 volumio volumio[26209]: assert.ok(self.idling) Mar 04 20:12:05 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 04 20:12:05 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 20:12:05 volumio volumio[26209]: info: Received Get System Info Mar 04 20:12:05 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:12:05 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:12:05 volumio volumio[26209]: info: Discovery: Getting this device information Mar 04 20:12:05 volumio volumio[26209]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:05 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:05 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:12:05 volumio volumio[26209]: info: MPD running with PID26409 Mar 04 20:12:05 volumio volumio[26209]: ,establishing connection Mar 04 20:12:05 volumio volumio[26209]: error: updateQueue error: null Mar 04 20:12:05 volumio volumio[26209]: error: updateQueue error: null Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=debug msg="completed challenge" Mar 04 20:12:05 volumio go-librespot[26515]: time="2026-03-04T20:12:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:06 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Mar 04 20:12:06 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 20:12:06 volumio volumio[26209]: info: Received Get System Info Mar 04 20:12:06 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:12:06 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:12:06 volumio volumio[26209]: info: Discovery: Getting this device information Mar 04 20:12:06 volumio volumio[26209]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:06 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:06 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:12:06 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Mar 04 20:12:07 volumio volumio[26209]: info: Initializing connection to go-librespot Websocket Mar 04 20:12:07 volumio volumio[26209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:12:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Mar 04 20:12:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:08 volumio go-librespot[26527]: go-librespot daemon starting... Mar 04 20:12:08 volumio go-librespot[26528]: time="2026-03-04T20:12:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:08 volumio go-librespot[26528]: time="2026-03-04T20:12:08+01:00" level=debug msg="app state loaded" Mar 04 20:12:08 volumio go-librespot[26528]: time="2026-03-04T20:12:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:09 volumio go-librespot[26528]: time="2026-03-04T20:12:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:09 volumio go-librespot[26528]: time="2026-03-04T20:12:09+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:09 volumio go-librespot[26528]: time="2026-03-04T20:12:09+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:09 volumio go-librespot[26528]: time="2026-03-04T20:12:09+01:00" level=info msg="zeroconf server listening on port 34179" Mar 04 20:12:09 volumio go-librespot[26528]: time="2026-03-04T20:12:09+01:00" level=debug msg="obtained new client token: AABJveJ9H+1ZKVzHUpU7QI/xWAbVoQsKZ1Xr+RoBjIFXPDRZd73se7MmRxaBDDYjasTj874tG/N4e/V5oYoLZVBF/FCfoELtAUuC85AAb4Mzq/82/zmdzewvEH5TNwEV8kIiiB5eNklWA/wk2o/CeV2cPlNewbe2BPygO49Aqc+aGqyVMGe9haBaVnz0xOZbzZM4u8uhN77sNVQ0pu7dbGtmlVEqeTTIiZfQHRoLXuKAu/fuglsCSc/olQ==" Mar 04 20:12:09 volumio go-librespot[26528]: time="2026-03-04T20:12:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:09 volumio go-librespot[26528]: time="2026-03-04T20:12:09+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:09 volumio go-librespot[26528]: time="2026-03-04T20:12:09+01:00" level=debug msg="completed challenge" Mar 04 20:12:09 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: wizard , setOnboardingWizardFalse Mar 04 20:12:09 volumio go-librespot[26528]: time="2026-03-04T20:12:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:10 volumio volumio[26209]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 20:12:10 volumio volumio[26209]: info: Initializing connection to go-librespot Websocket Mar 04 20:12:10 volumio volumio[26209]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:12:11 volumio volumio[26209]: info: CoreCommandRouter::volumioPlay Mar 04 20:12:11 volumio volumio[26209]: info: CoreStateMachine::play index undefined Mar 04 20:12:11 volumio volumio[26209]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:12:11 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:11 volumio volumio[26209]: info: CoreStateMachine::startPlaybackTimer Mar 04 20:12:11 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:12 volumio volumio[26209]: info: CoreCommandRouter::volumioPlay Mar 04 20:12:12 volumio volumio[26209]: info: CoreStateMachine::play index undefined Mar 04 20:12:12 volumio volumio[26209]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:12:12 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:12 volumio volumio[26209]: info: CoreStateMachine::startPlaybackTimer Mar 04 20:12:12 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Mar 04 20:12:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:12 volumio go-librespot[26549]: go-librespot daemon starting... Mar 04 20:12:12 volumio go-librespot[26550]: time="2026-03-04T20:12:12+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:12 volumio go-librespot[26550]: time="2026-03-04T20:12:12+01:00" level=debug msg="app state loaded" Mar 04 20:12:12 volumio go-librespot[26550]: time="2026-03-04T20:12:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:13 volumio go-librespot[26550]: time="2026-03-04T20:12:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 20:12:13 volumio go-librespot[26550]: time="2026-03-04T20:12:13+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 20:12:13 volumio go-librespot[26550]: time="2026-03-04T20:12:13+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 20:12:13 volumio go-librespot[26550]: time="2026-03-04T20:12:13+01:00" level=info msg="zeroconf server listening on port 35691" Mar 04 20:12:13 volumio volumio[26209]: info: CoreCommandRouter::volumioPlay Mar 04 20:12:13 volumio volumio[26209]: info: CoreStateMachine::play index undefined Mar 04 20:12:13 volumio volumio[26209]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:12:13 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:13 volumio volumio[26209]: info: CoreStateMachine::startPlaybackTimer Mar 04 20:12:13 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:13 volumio go-librespot[26550]: time="2026-03-04T20:12:13+01:00" level=debug msg="obtained new client token: AACIFoa7AhIMV63jK5n6V4vtqD+H6M/8ncJYX3NrwiHmW2Q//gn6rcIO5QzcK1uGaJ2prh68IuGMrTzfBC+p3QMltnuT2h1gBs2oOJO4wIjr0/MwgCXOdzQjqZ3/+k+V2KU6q85P1mlkqb/1ZWK+AP81bXtT/5n8JUQJHblmPem2r0psUx7vvNQ2w8byS3m9KRCh9HSWXzVgevQPeo+7SlGElFAyE0UkpZwr5T1vmvAxghbBUC/qYs64Jw==" Mar 04 20:12:13 volumio volumio[26209]: info: Initializing connection to go-librespot Websocket Mar 04 20:12:13 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 04 20:12:13 volumio go-librespot[26550]: time="2026-03-04T20:12:13+01:00" level=debug msg="new websocket client" Mar 04 20:12:13 volumio volumio[26209]: info: Connection to go-librespot Websocket established Mar 04 20:12:13 volumio go-librespot[26550]: time="2026-03-04T20:12:13+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:13 volumio go-librespot[26550]: time="2026-03-04T20:12:13+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:13 volumio go-librespot[26550]: time="2026-03-04T20:12:13+01:00" level=debug msg="completed challenge" Mar 04 20:12:13 volumio go-librespot[26550]: time="2026-03-04T20:12:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:13 volumio volumio[26209]: info: Connection to go-librespot Websocket closed Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 20:12:13 volumio volumio[26209]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 20:12:13 volumio volumio[26209]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 20:12:13 volumio volumio[26209]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 20:12:13 volumio volumio[26209]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 20:12:13 volumio volumio[26209]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 20:12:13 volumio volumio[26209]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 20:12:13 volumio volumio[26209]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 20:12:13 volumio volumio[26209]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 20:12:15 volumio volumio[26209]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 20:12:15 volumio volumio[26209]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 20:12:15 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:15 volumio volumio[26209]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:15 volumio volumio[26209]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 20:12:15 volumio volumio[26209]: info: MyVolumio login type: Token Mar 04 20:12:15 volumio volumio[26209]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 20:12:15 volumio volumio[26209]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 20:12:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Mar 04 20:12:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:16 volumio go-librespot[26557]: go-librespot daemon starting... Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=debug msg="app state loaded" Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=info msg="zeroconf server listening on port 38681" Mar 04 20:12:17 volumio volumio[26209]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 20:12:17 volumio volumio[26209]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 20:12:17 volumio volumio[26209]: info: Streaming services startup Mar 04 20:12:17 volumio volumio[26209]: info: Starting Streaming Daemon Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=debug msg="obtained new client token: AAA9VH1jOZuitvtCU0ELvQ1K8h0iuaYlfLCaT15dWBJHc+0FknrOQUF/KGpTT3KMSJHj36yHg0LxLvOpG3+e6szx8CaYZc4Q74qdAzD/4y6h2pJnZ8x68cglF7mvu7+ISAHRa4D7uRHQS0pFw4bDLnq9Bj1aNR6i1VqC0FO63y+PTqjgR3GKq50v6I7t+VZua/meaYjOCxDZvd+MoBtpTAS+b+77LPAQazT9wMDbgXBty2J3t8VqUintbg==" Mar 04 20:12:17 volumio sudo[26567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:12:17 volumio sudo[26567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:17 volumio volumio[26209]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:17 volumio sudo[26567]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=debug msg="completed challenge" Mar 04 20:12:17 volumio go-librespot[26558]: time="2026-03-04T20:12:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:17 volumio volumio[26209]: info: Getting Spotify volume Mar 04 20:12:17 volumio volumio[26209]: info: Initializing connection to go-librespot Websocket Mar 04 20:12:17 volumio volumio[26209]: info: CoreCommandRouter::volumioPlay Mar 04 20:12:17 volumio volumio[26209]: info: CoreStateMachine::play index undefined Mar 04 20:12:17 volumio volumio[26209]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:12:17 volumio volumio[26209]: info: CoreCommandRouter::volumioPlay Mar 04 20:12:17 volumio volumio[26209]: info: CoreStateMachine::play index undefined Mar 04 20:12:17 volumio volumio[26209]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 20:12:17 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:17 volumio volumio[26209]: info: CoreStateMachine::startPlaybackTimer Mar 04 20:12:17 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:17 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:17 volumio volumio[26209]: info: CoreStateMachine::startPlaybackTimer Mar 04 20:12:17 volumio volumio[26209]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:17 volumio volumio[26209]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:12:17 volumio volumio[26209]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:12:17 volumio volumio[26209]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 04 20:12:17 volumio volumio[26209]: errno: -111, Mar 04 20:12:17 volumio volumio[26209]: code: 'ECONNREFUSED', Mar 04 20:12:17 volumio volumio[26209]: syscall: 'connect', Mar 04 20:12:17 volumio volumio[26209]: address: '127.0.0.1', Mar 04 20:12:17 volumio volumio[26209]: port: 9879, Mar 04 20:12:17 volumio volumio[26209]: response: undefined Mar 04 20:12:17 volumio volumio[26209]: } Mar 04 20:12:17 volumio volumio[26209]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:12:19 volumio sudo[26596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 20:11' Mar 04 20:12:19 volumio sudo[26596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:19 volumio sudo[26596]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:19 volumio volumio-remote-updater[708]: [2026-03-04 20:12:19] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 04 20:12:19 volumio volumio-remote-updater[708]: [2026-03-04 20:12:19] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 04 20:12:19 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:19 volumio volumio5-onboarding[2437]: time=2026-03-04T20:12:19.744+01:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Mar 04 20:12:19 volumio volumio5-onboarding[2437]: time=2026-03-04T20:12:19.751+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 20:12:19 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 04 20:12:19 volumio systemd[1]: volumio.service: Consumed 46.359s CPU time. Mar 04 20:12:19 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 20:12:19 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 20:12:19 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 34. Mar 04 20:12:19 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 20:12:19 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 04 20:12:19 volumio systemd[1]: volumio.service: Consumed 46.359s CPU time. Mar 04 20:12:19 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Mar 04 20:12:19 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 20:12:20 volumio volumio5-onboarding[2437]: time=2026-03-04T20:12:20.752+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 20:12:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Mar 04 20:12:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:20 volumio go-librespot[26630]: go-librespot daemon starting... Mar 04 20:12:20 volumio go-librespot[26631]: time="2026-03-04T20:12:20+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:20 volumio go-librespot[26631]: time="2026-03-04T20:12:20+01:00" level=debug msg="app state loaded" Mar 04 20:12:20 volumio go-librespot[26631]: time="2026-03-04T20:12:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:21 volumio go-librespot[26631]: time="2026-03-04T20:12:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:21 volumio go-librespot[26631]: time="2026-03-04T20:12:21+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:21 volumio go-librespot[26631]: time="2026-03-04T20:12:21+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:21 volumio go-librespot[26631]: time="2026-03-04T20:12:21+01:00" level=info msg="zeroconf server listening on port 42081" Mar 04 20:12:21 volumio go-librespot[26631]: time="2026-03-04T20:12:21+01:00" level=debug msg="obtained new client token: AAA1YkmBd5gydAbg3IcyYsxv3ElsEDP5oLgu1p99XRRwHKNSDvHXo+mK+sAwvEdG51Bj0dpVMbDIqGiV1HkYwRzTugpTITVN97P0HBm0fUc1wQdPmDJIgJVbEGchr8RfFVpgww/DDCwaeVMtuEmw2LxZ+7pBLffuNiuPD48snuF57h6XjqDJXhvBDFj/9Z3tmHEmzlHO53kYaRbo6wacUflT7qMcVq/5qapT9UhYlB9h2adpfDch161JVQ==" Mar 04 20:12:21 volumio go-librespot[26631]: time="2026-03-04T20:12:21+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:21 volumio go-librespot[26631]: time="2026-03-04T20:12:21+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:21 volumio go-librespot[26631]: time="2026-03-04T20:12:21+01:00" level=debug msg="completed challenge" Mar 04 20:12:21 volumio go-librespot[26631]: time="2026-03-04T20:12:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:21 volumio volumio5-onboarding[2437]: time=2026-03-04T20:12:21.769+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 20:12:23 volumio volumio[26615]: info: ------------------------------------------- Mar 04 20:12:23 volumio volumio[26615]: info: ----- Volumio3 ---- Mar 04 20:12:23 volumio volumio[26615]: info: ------------------------------------------- Mar 04 20:12:23 volumio volumio[26615]: info: ----- System startup ---- Mar 04 20:12:23 volumio volumio[26615]: info: ------------------------------------------- Mar 04 20:12:24 volumio volumio[26615]: info: MYVOLUMIO Environment detected Mar 04 20:12:24 volumio volumio-remote-updater[708]: [2026-03-04 20:12:24] [connect] Successful connection Mar 04 20:12:24 volumio volumio[26615]: info: Plugin folders cleanup Mar 04 20:12:24 volumio volumio[26615]: info: Scanning into folder /volumio/app/plugins/ Mar 04 20:12:24 volumio volumio[26615]: info: Scanning category audio_interface Mar 04 20:12:24 volumio volumio[26615]: info: Scanning category miscellanea Mar 04 20:12:24 volumio volumio[26615]: info: Scanning category music_service Mar 04 20:12:24 volumio volumio[26615]: info: Scanning category plugins.json Mar 04 20:12:24 volumio volumio[26615]: info: Scanning category system_controller Mar 04 20:12:24 volumio volumio[26615]: info: Scanning category user_interface Mar 04 20:12:24 volumio volumio[26615]: info: Scanning into folder /data/plugins/ Mar 04 20:12:24 volumio volumio[26615]: info: Scanning category music_service Mar 04 20:12:24 volumio volumio[26615]: info: Plugin folders cleanup completed Mar 04 20:12:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Mar 04 20:12:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:24 volumio volumio[26615]: info: ------------------------------------------- Mar 04 20:12:24 volumio volumio[26615]: info: ----- Core plugins startup ---- Mar 04 20:12:24 volumio volumio[26615]: info: ------------------------------------------- Mar 04 20:12:24 volumio volumio[26615]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 20:12:24 volumio volumio[26615]: info: Adding plugin upnp to MyMusic Plugins Mar 04 20:12:24 volumio volumio[26615]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 20:12:24 volumio volumio[26615]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 20:12:24 volumio volumio[26615]: info: Loading plugins from folder /data/plugins/ Mar 04 20:12:24 volumio volumio[26615]: info: Loading plugin "system"... Mar 04 20:12:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:24 volumio go-librespot[26648]: go-librespot daemon starting... Mar 04 20:12:24 volumio go-librespot[26649]: time="2026-03-04T20:12:24+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:24 volumio go-librespot[26649]: time="2026-03-04T20:12:24+01:00" level=debug msg="app state loaded" Mar 04 20:12:24 volumio go-librespot[26649]: time="2026-03-04T20:12:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:24 volumio volumio[26615]: info: Loading plugin "appearance"... Mar 04 20:12:25 volumio go-librespot[26649]: time="2026-03-04T20:12:25+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:25 volumio go-librespot[26649]: time="2026-03-04T20:12:25+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:25 volumio go-librespot[26649]: time="2026-03-04T20:12:25+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:25 volumio go-librespot[26649]: time="2026-03-04T20:12:25+01:00" level=info msg="zeroconf server listening on port 44245" Mar 04 20:12:25 volumio go-librespot[26649]: time="2026-03-04T20:12:25+01:00" level=debug msg="obtained new client token: AAAwP69limOLwq6/6NsDO0cXIJ8jeVAzmwMrsFVBDuYzCkxAJsernzq5btCuWE1o0fIXG60DgjnebL0UpW8HYUaOrZ2/BnIwV9TjjJJgQ1kudN/Xua8i2zH/6ewRhl47cW+mpd22hndjhklyjeYw3R02Q3VJKo9mIX8Lp1q67AXJyJnl1yCV7hiRb6KhEx6q9pxQj6HcZRdPCIRkTXhBAWlU/o1G7SmiXE+Gfel5yrjDYB8vc01BO4NIuQ==" Mar 04 20:12:25 volumio go-librespot[26649]: time="2026-03-04T20:12:25+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:25 volumio go-librespot[26649]: time="2026-03-04T20:12:25+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:25 volumio go-librespot[26649]: time="2026-03-04T20:12:25+01:00" level=debug msg="completed challenge" Mar 04 20:12:25 volumio go-librespot[26649]: time="2026-03-04T20:12:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:26 volumio volumio[26615]: info: Loading plugin "network"... Mar 04 20:12:26 volumio volumio[26615]: info: Refreshing Cached IP Addresses Mar 04 20:12:26 volumio sudo[26660]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:12:26 volumio sudo[26660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:26 volumio volumio[26615]: info: Loading plugin "services"... Mar 04 20:12:26 volumio sudo[26662]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:12:26 volumio sudo[26662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:26 volumio volumio[26615]: info: Loading plugin "volumio5onboarding"... Mar 04 20:12:26 volumio sudo[26660]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:27 volumio sudo[26662]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:27 volumio volumio[26615]: info: Loading plugin "alsa_controller"... Mar 04 20:12:27 volumio sudo[26670]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 20:12:27 volumio sudo[26670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:27 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:12:27 volumio volumio[26615]: info: Loading plugin "wizard"... Mar 04 20:12:27 volumio volumio[26615]: info: Loading plugin "networkfs"... Mar 04 20:12:27 volumio volumio[26615]: info: Starting Udev Watcher for removable devices Mar 04 20:12:27 volumio volumio[26615]: info: Ignoring mount for partition: boot Mar 04 20:12:27 volumio volumio[26615]: info: Ignoring mount for partition: volumio Mar 04 20:12:27 volumio volumio[26615]: info: Ignoring mount for partition: volumio_data Mar 04 20:12:27 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:12:27 volumio volumio[26615]: info: Loading plugin "volumio_command_line_client"... Mar 04 20:12:27 volumio volumio[26615]: info: Loading plugin "upnp"... Mar 04 20:12:27 volumio volumio[26615]: info: [1772651547321] Starting Upmpd Daemon Mar 04 20:12:27 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:12:27 volumio volumio[26615]: info: Loading plugin "my_music"... Mar 04 20:12:27 volumio volumio[26615]: info: Loading plugin "mpd"... Mar 04 20:12:27 volumio sudo[26670]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:27 volumio volumio[26615]: info: Loading plugin "upnp_browser"... Mar 04 20:12:28 volumio volumio5-onboarding[2437]: time=2026-03-04T20:12:28.156+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.178.147:56938 @ 0x24a6720" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 04 20:12:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Mar 04 20:12:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:28 volumio go-librespot[26694]: go-librespot daemon starting... Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=debug msg="app state loaded" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=info msg="zeroconf server listening on port 44899" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=debug msg="obtained new client token: AABte0MxKm82p9yIUQ2hiw3s3EC5NKn+8Cma1n9HcEytP7RBv6ktSSbXfs1jO9U5RWDxbWO/l9eCmb3DIrnRgk1kXf68IUBog2DuxPTjG9xCpqgj7J4D8pW+j9pzoPqIWO34Ub6adVKznbSDZQcn82GmD1sC2cxQ5inCGGC6QeuzClaaysOHcuoACop4nXt6eXsGoDYmHTL5sEqP1yEMNEDimiN0xlosxFZVQKizsYKRkysvjoS17gujTA==" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=debug msg="completed challenge" Mar 04 20:12:29 volumio go-librespot[26695]: time="2026-03-04T20:12:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:30 volumio volumio[26615]: info: Starting UPNP Browser Mar 04 20:12:30 volumio volumio[26615]: info: Loading plugin "alarm-clock"... Mar 04 20:12:31 volumio volumio[26615]: info: Loading plugin "airplay_emulation"... Mar 04 20:12:31 volumio volumio[26615]: info: Starting Shairport Sync Mar 04 20:12:31 volumio volumio[26615]: info: Loading plugin "last_100"... Mar 04 20:12:31 volumio volumio[26615]: info: Loading plugin "webradio"... Mar 04 20:12:31 volumio volumio[26615]: info: Loading plugin "i2s_dacs"... Mar 04 20:12:31 volumio volumio[26615]: info: Loading plugin "volumiodiscovery"... Mar 04 20:12:31 volumio volumio[26615]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:12:31 volumio volumio[26615]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:12:31 volumio node[26615]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 20:12:31 volumio volumio[26615]: *** WARNING *** For more information see Mar 04 20:12:31 volumio volumio[26615]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:12:31 volumio volumio[26615]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:12:31 volumio volumio[26615]: *** WARNING *** For more information see Mar 04 20:12:31 volumio node[26615]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:12:31 volumio node[26615]: *** WARNING *** For more information see Mar 04 20:12:31 volumio node[26615]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 20:12:31 volumio node[26615]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 20:12:31 volumio node[26615]: *** WARNING *** For more information see Mar 04 20:12:31 volumio volumio[26615]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 20:12:31 volumio volumio[26615]: info: Discovery: Started advertising with name: Volumio Mar 04 20:12:31 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 20:12:31 volumio volumio[26615]: info: Loading plugin "spop"... Mar 04 20:12:32 volumio volumio5-onboarding[2437]: time=2026-03-04T20:12:32.770+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:35758->127.0.0.1:3000: i/o timeout" Mar 04 20:12:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Mar 04 20:12:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:32 volumio go-librespot[26704]: go-librespot daemon starting... Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=debug msg="app state loaded" Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:33 volumio volumio[26615]: info: Loading plugin "outputs"... Mar 04 20:12:33 volumio volumio[26615]: info: Loading plugin "albumart"... Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=info msg="zeroconf server listening on port 43353" Mar 04 20:12:33 volumio volumio[26615]: info: Plugin example_plugin is not enabled Mar 04 20:12:33 volumio volumio[26615]: info: Loading plugin "inputs"... Mar 04 20:12:33 volumio volumio[26615]: info: Loading plugin "updater_comm"... Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=debug msg="obtained new client token: AADALiS5IB0PED8O+Y8QOu7f0l+q6rtJzwI04v72uO0Na0SX+8kvB0EoEjRVn4N1QppcAreJllKQFftuA8rANon47PCV/m8pxLWXa/zUM7IlK5HmSsab3vVUVWqUK0N1zHar5gWUGmLPJHLFP/x7PN3SoNqk576xFSdPNk7VjypJT5zsoX8M/bB4Dk6VjgyCbFiLRZu6aVrMqLfH3Q3jmiTYR/Ddn5qlNaqqhQBnumDOPDz8pJ8oNTNoQQ==" Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:33 volumio volumio[26615]: info: Plugin mpdemulation is not enabled Mar 04 20:12:33 volumio volumio[26615]: info: Loading plugin "rest_api"... Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=debug msg="completed challenge" Mar 04 20:12:33 volumio volumio[26615]: info: Loading plugin "websocket"... Mar 04 20:12:33 volumio go-librespot[26705]: time="2026-03-04T20:12:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:33 volumio volumio[26615]: info: Starting Socket.io Server version 1.7.4 Mar 04 20:12:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:33 volumio volumio[26615]: info: Loading i18n strings for locale nl Mar 04 20:12:33 volumio volumio[26615]: Updating browse sources language Mar 04 20:12:33 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::initPlayerControls Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: Express server listening on port 3000 Mar 04 20:12:34 volumio volumio[26615]: [Metrics] WebUI: 11s 637.57ms Mar 04 20:12:34 volumio volumio[26615]: info: CoreStateMachine::resetVolumioState Mar 04 20:12:34 volumio volumio[26615]: info: CoreStateMachine::getcurrentVolume Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:12:34 volumio volumio[26615]: info: Volumio Network Manager: Network status updated: 1 Mar 04 20:12:34 volumio volumio[26712]: Forking 3 albumart workers Mar 04 20:12:34 volumio volumio[26615]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:34 volumio volumio[26615]: info: Reloading queue from file Mar 04 20:12:34 volumio volumio[26615]: info: VolumeController:: Volume=5 Mute =false Mar 04 20:12:34 volumio volumio[26615]: info: CoreStateMachine::pushState Mar 04 20:12:34 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::volumioPushState Mar 04 20:12:34 volumio volumio[26615]: info: CoreStateMachine::updateTrackBlock Mar 04 20:12:34 volumio volumio[26615]: info: CorePlayQueue::getTrackBlock Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 20:12:34 volumio volumio[26615]: info: CoreStateMachine::setRepeat false single undefined Mar 04 20:12:34 volumio volumio[26615]: info: CoreStateMachine::pushState Mar 04 20:12:34 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::volumioPushState Mar 04 20:12:34 volumio volumio[26615]: info: CoreStateMachine::setRandom undefined Mar 04 20:12:34 volumio volumio[26615]: info: CoreStateMachine::pushState Mar 04 20:12:34 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 20:12:34 volumio volumio[26615]: info: CoreCommandRouter::volumioPushState Mar 04 20:12:34 volumio volumio[26615]: info: Setting Device type: Raspberry PI Mar 04 20:12:34 volumio volumio[26615]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Mar 04 20:12:34 volumio volumio[26615]: info: Completed loading Core Plugins Mar 04 20:12:34 volumio volumio[26615]: info: Preparing to generate the ALSA configuration file Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:12:35 volumio volumio[26615]: info: Discovery: Getting this device information Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:35 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:12:35 volumio volumio[26615]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Mar 04 20:12:35 volumio volumio[26615]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:12:35 volumio volumio[26615]: info: VolumeController:: Volume=5 Mute =false Mar 04 20:12:35 volumio volumio[26615]: info: CoreStateMachine::pushState Mar 04 20:12:35 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::volumioPushState Mar 04 20:12:35 volumio volumio[26615]: info: Asound.conf file unchanged, so no further update is needed Mar 04 20:12:35 volumio volumio[26615]: info: Output device has changed, restarting MPD Mar 04 20:12:35 volumio volumio[26615]: info: Output device has changed, restarting Shairport Sync Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:35 volumio sudo[26769]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:12:35 volumio sudo[26769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:35 volumio sudo[26769]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:35 volumio volumio[26615]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:12:35 volumio sudo[26770]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:12:35 volumio sudo[26770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:35 volumio volumio[26615]: info: ___________ START PLUGINS ___________ Mar 04 20:12:35 volumio volumio[26615]: info: ControllerMpd::onStart: Initializing MPD Mar 04 20:12:35 volumio volumio[26615]: info: Creating MPD Configuration file Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:12:35 volumio volumio[26615]: info: [1772651555378] CoreMusicLibrary::Adding element Media Servers Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:12:35 volumio volumio[26615]: info: UPNP Browser: Client initialized successfully Mar 04 20:12:35 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:35 volumio sudo[26778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 04 20:12:35 volumio sudo[26778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:35 volumio sudo[26782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 20:12:35 volumio volumio[26615]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:35 volumio sudo[26782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:35 volumio sudo[26780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 20:12:35 volumio sudo[26780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:35 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:12:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:12:35 volumio systemd[1]: mpd.service: Consumed 6.995s CPU time. Mar 04 20:12:35 volumio sudo[26780]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:35 volumio volumio[26615]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:12:35 volumio volumio[26615]: info: [1772651555645] CoreMusicLibrary::Adding element Last_100 Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:12:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 20:12:35 volumio volumio[26615]: info: [1772651555668] CoreMusicLibrary::Adding element Webradio Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:12:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:12:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:12:35 volumio volumio[26615]: info: Initializing BBC Radios Mar 04 20:12:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:12:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:12:35 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 04 20:12:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 20:12:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 04 20:12:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 20:12:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:35 volumio volumio[26615]: info: Creating Spotify config file Mar 04 20:12:35 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 20:12:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 20:12:36 volumio sudo[26778]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:36 volumio sudo[26810]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 20:12:36 volumio sudo[26810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 20:12:36 volumio sudo[26810]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:36 volumio volumio[26615]: info: Volumio Calling Home Mar 04 20:12:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Mar 04 20:12:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:37 volumio go-librespot[26820]: go-librespot daemon starting... Mar 04 20:12:37 volumio volumio-remote-updater[708]: [2026-03-04 20:12:37] [connect] Successful connection Mar 04 20:12:37 volumio go-librespot[26825]: time="2026-03-04T20:12:37+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:37 volumio volumio[26615]: info: Discovery: adding 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 20:12:37 volumio volumio[26615]: info: Discovery: Found device Volumio Mar 04 20:12:37 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:37 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:37 volumio volumio[26615]: verbose: New Socket.io Connection to 192.168.178.145:3000 from 192.168.178.147 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 4 Mar 04 20:12:37 volumio volumio[26731]: Starting albumart workers Mar 04 20:12:37 volumio volumio[26615]: info: Discovery: this is already registered, 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 20:12:37 volumio volumio[26615]: info: Discovery: Found device Volumio Mar 04 20:12:37 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:37 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:37 volumio go-librespot[26825]: time="2026-03-04T20:12:37+01:00" level=info msg="zeroconf server listening on port 43701" Mar 04 20:12:37 volumio sudo[26839]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 20:12:37 volumio sudo[26839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:37 volumio sudo[26839]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:37 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 20:12:37 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 20:12:37 volumio sudo[26841]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 20:12:37 volumio sudo[26841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:37 volumio sudo[26841]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:38 volumio volumio[26615]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Mar 04 20:12:38 volumio volumio[26615]: info: MPD Permissions set Mar 04 20:12:38 volumio volumio[26615]: info: MPD Permissions set Mar 04 20:12:38 volumio volumio[26615]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Mar 04 20:12:38 volumio volumio[26615]: info: Received Get System Info Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:12:38 volumio volumio[26615]: info: Discovery: Getting this device information Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:38 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:12:38 volumio volumio5-onboarding[2437]: time=2026-03-04T20:12:38.161+01:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to check if setup wizard should be shown: could not get wizard status: context deadline exceeded" Mar 04 20:12:38 volumio volumio[26730]: Starting albumart workers Mar 04 20:12:38 volumio volumio-remote-updater[708]: [2026-03-04 20:12:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772651557 101 Mar 04 20:12:38 volumio volumio[26615]: 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: 6 Mar 04 20:12:38 volumio volumio[26615]: info: Volumio called home Mar 04 20:12:38 volumio volumio[26615]: info: Spotify config file written Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 20:12:38 volumio sudo[26845]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 20:12:38 volumio sudo[26845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:38 volumio volumio[26729]: Starting albumart workers Mar 04 20:12:38 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 04 20:12:38 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 04 20:12:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:38 volumio volumio[26615]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Mar 04 20:12:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:38 volumio go-librespot[26847]: go-librespot daemon starting... Mar 04 20:12:38 volumio sudo[26845]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio go-librespot[26848]: time="2026-03-04T20:12:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:38 volumio go-librespot[26848]: time="2026-03-04T20:12:38+01:00" level=debug msg="app state loaded" Mar 04 20:12:38 volumio go-librespot[26848]: time="2026-03-04T20:12:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 20:12:38 volumio volumio[26615]: info: No need to fix Spotify hosts Mar 04 20:12:39 volumio volumio[26615]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 04 20:12:39 volumio go-librespot[26848]: time="2026-03-04T20:12:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:39 volumio go-librespot[26848]: time="2026-03-04T20:12:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:39 volumio go-librespot[26848]: time="2026-03-04T20:12:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:39 volumio go-librespot[26848]: time="2026-03-04T20:12:39+01:00" level=info msg="zeroconf server listening on port 35445" Mar 04 20:12:39 volumio volumio[26615]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 04 20:12:39 volumio go-librespot[26848]: time="2026-03-04T20:12:39+01:00" level=debug msg="obtained new client token: AAA2D0AnbqpOpSPuSxUFxuxopc0mzqO6WrMOOpsx2iFeWao/NFpXN9Hul1+AvyibEfM+adJ/YxOKEXv8dp3FiOg+xwWE5YUsbxh3afqWXZHySeKPAAm3SFT2yAb9yix9VLFqYoBZA5/kX+vP1tTNIHUSkQtvwk66FppBww2u6xeI0POYmCc67UoL7R0g7fiBjWhtyqlPRb3Ts7hHSc6TeJz4U2kg15Oy1JxX2+kD9EL/Nz7HF50wM6iudA==" Mar 04 20:12:39 volumio go-librespot[26848]: time="2026-03-04T20:12:39+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 20:12:39 volumio volumio[26615]: info: Starting Shairport Sync Mar 04 20:12:39 volumio go-librespot[26848]: time="2026-03-04T20:12:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 20:12:39 volumio volumio[26615]: info: Starting Shairport Sync Mar 04 20:12:39 volumio volumio[26615]: info: Starting Shairport Sync Mar 04 20:12:39 volumio go-librespot[26848]: time="2026-03-04T20:12:39+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:39 volumio go-librespot[26848]: time="2026-03-04T20:12:39+01:00" level=debug msg="completed challenge" Mar 04 20:12:39 volumio go-librespot[26848]: time="2026-03-04T20:12:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:39 volumio sudo[26868]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:12:39 volumio sudo[26879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 20:12:39 volumio sudo[26877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:12:39 volumio sudo[26879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:39 volumio sudo[26877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:39 volumio sudo[26872]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 20:12:39 volumio sudo[26872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:40 volumio sudo[26868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:40 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 20:12:40 volumio sudo[26879]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:40 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 20:12:40 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:12:40 volumio systemd[1]: shairport-sync.service: Consumed 2.182s CPU time. Mar 04 20:12:40 volumio volumio[26615]: info: Upmpdcli Daemon Started Mar 04 20:12:40 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 20:12:40 volumio sudo[26872]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:40 volumio sudo[26877]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:40 volumio sudo[26868]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:40 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:40 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:40 volumio volumio[26615]: info: Shairport-Sync Started Mar 04 20:12:40 volumio volumio[26615]: Error adding Membership: Error: addMembership EINVAL Mar 04 20:12:40 volumio volumio[26615]: info: Shairport-Sync Started Mar 04 20:12:40 volumio volumio[26615]: info: Shairport-Sync Started Mar 04 20:12:42 volumio volumio[26615]: info: go-librespot daemon successfully initialized Mar 04 20:12:43 volumio mpd[26812]: 2026-03-04T20:12:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 20:12:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 04 20:12:43 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 20:12:43 volumio sudo[26770]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:43 volumio sudo[26782]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:43 volumio volumio[26615]: info: Completed starting Core Plugins Mar 04 20:12:43 volumio volumio[26615]: info: ------------------------------------------- Mar 04 20:12:43 volumio volumio[26615]: info: ----- MyVolumio plugins startup ---- Mar 04 20:12:43 volumio volumio[26615]: info: ------------------------------------------- Mar 04 20:12:43 volumio volumio[26615]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 20:12:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:43 volumio go-librespot[26913]: go-librespot daemon starting... Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=debug msg="app state loaded" Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:43 volumio volumio[26615]: error: MPD error: The expression evaluated to a falsy value: Mar 04 20:12:43 volumio volumio[26615]: assert.ok(self.idling) Mar 04 20:12:43 volumio volumio[26615]: error: The expression evaluated to a falsy value: Mar 04 20:12:43 volumio volumio[26615]: assert.ok(self.idling) Mar 04 20:12:43 volumio volumio[26615]: error: updateQueue error: null Mar 04 20:12:43 volumio volumio[26615]: info: MPD running with PID26812 Mar 04 20:12:43 volumio volumio[26615]: ,establishing connection Mar 04 20:12:43 volumio volumio[26615]: error: updateQueue error: null Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=info msg="zeroconf server listening on port 37005" Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=debug msg="obtained new client token: AADunWasdo/bxGI4wgssnNSi8oJAu/gEVvITZXa1RPxMCV1tWwObacV+ID4lpRkRmiyEeLxAyNLRSSxWFAXS+VJebiYvP9zNBKsxfJ2E6vSLlxXU/WP4HeT3qG4jA+ulgVLHmDMfBaQm9L/r85bcvTQec8NAyQubopMzIBPD/i7dwiaNjNYI/NuvsGNI9um5p1mU4R6PjSTF21rLiv+tW/OvNW2MSLjC69d0SyeM21d3d9gEgoESsG8y6g==" Mar 04 20:12:43 volumio volumio[26615]: verbose: New Socket.io Connection to 192.168.178.145 from 192.168.178.147 UA: Mozilla/5.0 (Linux; Android 16; SM-A566B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:43 volumio volumio[26615]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=debug msg="completed challenge" Mar 04 20:12:43 volumio volumio[26615]: info: Received Get System Version Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 20:12:43 volumio volumio[26615]: info: Received Get System Info Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:12:43 volumio volumio[26615]: info: Discovery: Getting this device information Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:43 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:43 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:43 volumio go-librespot[26916]: time="2026-03-04T20:12:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:43 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 04 20:12:44 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 04 20:12:44 volumio volumio[26615]: info: Received Get System Info Mar 04 20:12:44 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 20:12:44 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 20:12:44 volumio volumio[26615]: info: Discovery: Getting this device information Mar 04 20:12:44 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:44 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:44 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 20:12:44 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:44 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:44 volumio volumio[26615]: info: Listing playlists Mar 04 20:12:44 volumio volumio[26615]: info: CoreCommandRouter::volumioGetQueue Mar 04 20:12:44 volumio volumio[26615]: info: CoreStateMachine::getQueue Mar 04 20:12:44 volumio volumio[26615]: info: CorePlayQueue::getQueue Mar 04 20:12:45 volumio volumio[26615]: info: Initializing connection to go-librespot Websocket Mar 04 20:12:45 volumio volumio[26615]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:12:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 04 20:12:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:47 volumio go-librespot[26924]: go-librespot daemon starting... Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=debug msg="app state loaded" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=info msg="zeroconf server listening on port 45697" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=debug msg="obtained new client token: AABP/vcbbvPXMj4MMwhUCA+8Dhpl/FhRRkWjmmO7+Oh3CsM2yY6RAYcRz27O53xiTpdIbX+wGMDs1Yfz6mWzFljaa4sT/xcCozbY1RbxutPeyfHYYvTIxiyyXi7UytCugGdZQxzOy9C4DmGJ6S51oY78mW7y6hOi3G6EUlAR+BcCmcrQFKlca64/50n+41Mw14FVb3dPCz7oFNeTyRuLGvdLAKlwgrthnP63Ha2z6BTrZ2A+zBGXcku4LA==" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=debug msg="completed challenge" Mar 04 20:12:47 volumio go-librespot[26925]: time="2026-03-04T20:12:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:48 volumio volumio[26615]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 20:12:48 volumio volumio[26615]: info: Initializing connection to go-librespot Websocket Mar 04 20:12:48 volumio volumio[26615]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 20:12:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 04 20:12:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:51 volumio go-librespot[26947]: go-librespot daemon starting... Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=debug msg="app state loaded" Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:51 volumio volumio[26615]: info: Initializing connection to go-librespot Websocket Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=debug msg="new websocket client" Mar 04 20:12:51 volumio volumio[26615]: info: Connection to go-librespot Websocket established Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=info msg="zeroconf server listening on port 38311" Mar 04 20:12:51 volumio volumio[26615]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 20:12:51 volumio volumio[26615]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 20:12:51 volumio volumio[26615]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 20:12:51 volumio volumio[26615]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 20:12:51 volumio volumio[26615]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 20:12:51 volumio volumio[26615]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 20:12:51 volumio volumio[26615]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 20:12:51 volumio volumio[26615]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=debug msg="obtained new client token: AACupfw0snZH1TLpF4PtW/sqSsbMvTChBeHB7iFguG6SWUv5KDyPizv8CLSWacGDkCdamfGRwhhEe2Gq4NalzpXUt95pbJVzGEuPcJAHNbktjMOHmBNJR63UVY/nC1LrgT257pYBBAlBvjRfO+cAPACOlRf60UQowo534kOwGWRcWM1+yS/FkyHa2az/Im8lseb3pmK31Nkv37S9XxLkUDcWFmyG383p7QFAl1g4w6O6edBgeXCcFAWtfA==" Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=debug msg="completed challenge" Mar 04 20:12:51 volumio go-librespot[26948]: time="2026-03-04T20:12:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:53 volumio volumio[26615]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 20:12:53 volumio volumio[26615]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 20:12:53 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:53 volumio volumio[26615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 20:12:53 volumio volumio[26615]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 20:12:53 volumio volumio[26615]: info: MyVolumio login type: Token Mar 04 20:12:53 volumio volumio[26615]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 20:12:53 volumio volumio[26615]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 20:12:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 04 20:12:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 20:12:55 volumio go-librespot[26956]: go-librespot daemon starting... Mar 04 20:12:55 volumio go-librespot[26957]: time="2026-03-04T20:12:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 20:12:55 volumio go-librespot[26957]: time="2026-03-04T20:12:55+01:00" level=debug msg="app state loaded" Mar 04 20:12:55 volumio go-librespot[26957]: time="2026-03-04T20:12:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 20:12:55 volumio volumio[26615]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 20:12:55 volumio volumio[26615]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 20:12:55 volumio volumio[26615]: info: Streaming services startup Mar 04 20:12:55 volumio volumio[26615]: info: Starting Streaming Daemon Mar 04 20:12:55 volumio volumio[26615]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 20:12:55 volumio sudo[26965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 20:12:55 volumio sudo[26965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 20:12:55 volumio sudo[26965]: pam_unix(sudo:session): session closed for user root Mar 04 20:12:55 volumio volumio[26615]: info: Getting Spotify volume Mar 04 20:12:55 volumio volumio[26615]: info: Connection to go-librespot Websocket closed Mar 04 20:12:55 volumio volumio[26615]: error: Cannot start Volumio Streaming Daemon Mar 04 20:12:55 volumio volumio[26615]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 20:12:55 volumio volumio[26615]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 20:12:55 volumio volumio[26615]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 04 20:12:55 volumio go-librespot[26957]: time="2026-03-04T20:12:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 20:12:55 volumio go-librespot[26957]: time="2026-03-04T20:12:55+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 20:12:55 volumio go-librespot[26957]: time="2026-03-04T20:12:55+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 20:12:55 volumio go-librespot[26957]: time="2026-03-04T20:12:55+01:00" level=info msg="zeroconf server listening on port 35373" Mar 04 20:12:55 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:55 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:55 volumio go-librespot[26957]: time="2026-03-04T20:12:55+01:00" level=debug msg="obtained new client token: AAAIOnernVb3xrWsDoePcVeLLf1xeHrBrxTYZ6uAbo+Vm+7Mtue15hnZt12c7mIMldKhbzfGD7DyDFEvuNYE6NKHMsUit7nzeYA36MpB/SrWqsES0XE/VVHc0+9IQXRGhdq5xwavcm1JyJeqfg23+sL1TXeEOuyaJHUs5fPt5W+E8D8JahZ5qp2/PI7ool0NrQyCxCakVSS3yrTYwhjn2Au0o3npsgbOEPj3UrgbaHjdDBcG9YMjo/WBhw==" Mar 04 20:12:55 volumio volumio[26615]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 04 20:12:55 volumio volumio[26615]: SPOTIFY: SPOTIFY VOLUME undefined Mar 04 20:12:55 volumio volumio[26615]: SPOTIFY: VOLUMIO VOLUME 5 Mar 04 20:12:55 volumio volumio[26615]: info: Aligning Spotify Volume to Volumio Volume Mar 04 20:12:55 volumio volumio[26615]: info: CoreCommandRouter::volumioGetState Mar 04 20:12:55 volumio volumio[26615]: info: CorePlayQueue::getTrack 0 Mar 04 20:12:55 volumio volumio[26615]: info: Setting Spotify Volume from Volumio: 5 Mar 04 20:12:55 volumio go-librespot[26957]: time="2026-03-04T20:12:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 20:12:56 volumio go-librespot[26957]: time="2026-03-04T20:12:56+01:00" level=debug msg="completed keyexchange" Mar 04 20:12:56 volumio go-librespot[26957]: time="2026-03-04T20:12:56+01:00" level=debug msg="completed challenge" Mar 04 20:12:56 volumio go-librespot[26957]: time="2026-03-04T20:12:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 20:12:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 20:12:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 20:12:56 volumio volumio[26615]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:12:56 volumio volumio[26615]: Error: socket hang up Mar 04 20:12:56 volumio volumio[26615]: at connResetException (node:internal/errors:720:14) Mar 04 20:12:56 volumio volumio[26615]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 04 20:12:56 volumio volumio[26615]: at Socket.emit (node:events:526:35) Mar 04 20:12:56 volumio volumio[26615]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 04 20:12:56 volumio volumio[26615]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 04 20:12:56 volumio volumio[26615]: code: 'ECONNRESET', Mar 04 20:12:56 volumio volumio[26615]: response: undefined Mar 04 20:12:56 volumio volumio[26615]: } Mar 04 20:12:56 volumio volumio[26615]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 20:12:57 volumio sudo[26985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 20:11' Mar 04 20:12:57 volumio sudo[26985]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"