Feb 17 18:29:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 17 18:29:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:00 volumio go-librespot[28416]: go-librespot daemon starting... Feb 17 18:29:00 volumio go-librespot[28417]: time="2026-02-17T18:29:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:00 volumio go-librespot[28417]: time="2026-02-17T18:29:00+07:00" level=debug msg="app state loaded" Feb 17 18:29:00 volumio go-librespot[28417]: time="2026-02-17T18:29:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:00 volumio go-librespot[28417]: time="2026-02-17T18:29:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 18:29:00 volumio go-librespot[28417]: time="2026-02-17T18:29:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 18:29:00 volumio go-librespot[28417]: time="2026-02-17T18:29:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 18:29:00 volumio go-librespot[28417]: time="2026-02-17T18:29:00+07:00" level=info msg="zeroconf server listening on port 43569" Feb 17 18:29:01 volumio go-librespot[28417]: time="2026-02-17T18:29:01+07:00" level=debug msg="obtained new client token: AAD2mD82Vb9dzQtrUHAR5hjcA20DMYsRU/ikKYnErtngTgoJBgN2MmvOvJz6uODOEjfEp3UqA/LuBEKQ7cYlM/ue06qqoxgIJ4H3doLcEvht8hGkI3CgPe5lGRGHnUjf51mznH4X/lPX7PYAp6Qbc8ZqRO6C+jVZgPH0dMfPt1xaUR+xTrS2QEc9kYTnztx0FdqPLDxaOUJKyuq5HkviyczMPtv0LX+CQNBPwFwPwZJ6M9e2dWwl2wY=" Feb 17 18:29:01 volumio go-librespot[28417]: time="2026-02-17T18:29:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:01 volumio go-librespot[28417]: time="2026-02-17T18:29:01+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:01 volumio go-librespot[28417]: time="2026-02-17T18:29:01+07:00" level=debug msg="completed challenge" Feb 17 18:29:01 volumio go-librespot[28417]: time="2026-02-17T18:29:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:01 volumio volumio[28376]: info: Loading plugin "network"... Feb 17 18:29:01 volumio volumio[28376]: info: Refreshing Cached IP Addresses Feb 17 18:29:01 volumio sudo[28426]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 18:29:01 volumio sudo[28426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:01 volumio sudo[28428]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 18:29:01 volumio sudo[28428]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:01 volumio sudo[28426]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:01 volumio sudo[28428]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:01 volumio volumio[28376]: info: Loading plugin "services"... Feb 17 18:29:01 volumio volumio[28376]: info: Loading plugin "alsa_controller"... Feb 17 18:29:01 volumio sudo[28436]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 18:29:01 volumio sudo[28436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:02 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 18:29:02 volumio volumio[28376]: info: Loading plugin "wizard"... Feb 17 18:29:02 volumio volumio[28376]: info: Loading plugin "networkfs"... Feb 17 18:29:02 volumio volumio[28376]: info: Starting Udev Watcher for removable devices Feb 17 18:29:02 volumio volumio[28376]: info: Ignoring mount for partition: boot Feb 17 18:29:02 volumio volumio[28376]: info: Ignoring mount for partition: volumio Feb 17 18:29:02 volumio volumio[28376]: info: Ignoring mount for partition: volumio_data Feb 17 18:29:02 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 18:29:02 volumio volumio[28376]: info: Loading plugin "volumio_command_line_client"... Feb 17 18:29:02 volumio volumio[28376]: info: Loading plugin "upnp"... Feb 17 18:29:02 volumio volumio[28376]: info: [1771327742255] Starting Upmpd Daemon Feb 17 18:29:02 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 18:29:02 volumio volumio[28376]: info: Loading plugin "my_music"... Feb 17 18:29:02 volumio volumio[28376]: info: Loading plugin "mpd"... Feb 17 18:29:02 volumio volumio[28376]: info: Loading plugin "upnp_browser"... Feb 17 18:29:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 17 18:29:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:04 volumio go-librespot[28459]: go-librespot daemon starting... Feb 17 18:29:04 volumio go-librespot[28460]: time="2026-02-17T18:29:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:04 volumio go-librespot[28460]: time="2026-02-17T18:29:04+07:00" level=debug msg="app state loaded" Feb 17 18:29:04 volumio go-librespot[28460]: time="2026-02-17T18:29:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:04 volumio sudo[28436]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:05 volumio go-librespot[28460]: time="2026-02-17T18:29:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:29:05 volumio go-librespot[28460]: time="2026-02-17T18:29:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:29:05 volumio go-librespot[28460]: time="2026-02-17T18:29:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:29:05 volumio go-librespot[28460]: time="2026-02-17T18:29:05+07:00" level=info msg="zeroconf server listening on port 36309" Feb 17 18:29:05 volumio go-librespot[28460]: time="2026-02-17T18:29:05+07:00" level=debug msg="obtained new client token: AAAObGF9qGHg4n7ZdzgLbwRoh5wKNPwcNYteqA6IYIamRiVrE0bxgl+h8t5xiWsCcspfWchwh0mlOa9tqQajY4xsk1WGv++7TfmBbF8qLALlVCsraKsIEqq/g3MIJbuzHe/Grip5j+PCOYW0H464PU980HH1uqn0jw4gvjsQ8EaSBmh84Xvbqex9FrJ94WVYpOmIFjZa7oK4oGidVgoW1fwHNV0TUc21zfJhB0iwoBjjghz4XMBQMSCMlQ==" Feb 17 18:29:05 volumio go-librespot[28460]: time="2026-02-17T18:29:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:05 volumio go-librespot[28460]: time="2026-02-17T18:29:05+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:05 volumio go-librespot[28460]: time="2026-02-17T18:29:05+07:00" level=debug msg="completed challenge" Feb 17 18:29:05 volumio go-librespot[28460]: time="2026-02-17T18:29:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:05 volumio volumio[28376]: info: Starting UPNP Browser Feb 17 18:29:05 volumio volumio[28376]: info: Loading plugin "alarm-clock"... Feb 17 18:29:06 volumio volumio[28376]: info: Loading plugin "airplay_emulation"... Feb 17 18:29:06 volumio volumio[28376]: info: Starting Shairport Sync Feb 17 18:29:06 volumio volumio[28376]: info: Loading plugin "last_100"... Feb 17 18:29:06 volumio volumio[28376]: info: Loading plugin "webradio"... Feb 17 18:29:06 volumio volumio[28376]: info: Loading plugin "i2s_dacs"... Feb 17 18:29:06 volumio volumio[28376]: info: Loading plugin "volumiodiscovery"... Feb 17 18:29:06 volumio volumio[28376]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 18:29:06 volumio volumio[28376]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 18:29:06 volumio volumio[28376]: *** WARNING *** For more information see Feb 17 18:29:06 volumio volumio[28376]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 18:29:06 volumio volumio[28376]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 18:29:06 volumio volumio[28376]: *** WARNING *** For more information see Feb 17 18:29:06 volumio node[28376]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 18:29:06 volumio node[28376]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 18:29:06 volumio node[28376]: *** WARNING *** For more information see Feb 17 18:29:06 volumio node[28376]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 18:29:06 volumio node[28376]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 18:29:06 volumio node[28376]: *** WARNING *** For more information see Feb 17 18:29:06 volumio volumio[28376]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 18:29:06 volumio volumio[28376]: info: Discovery: Started advertising with name: Volumio Feb 17 18:29:06 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 18:29:06 volumio volumio[28376]: info: Loading plugin "spop"... Feb 17 18:29:08 volumio volumio[28376]: info: Loading plugin "ytcr"... Feb 17 18:29:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 17 18:29:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:08 volumio go-librespot[28469]: go-librespot daemon starting... Feb 17 18:29:08 volumio go-librespot[28470]: time="2026-02-17T18:29:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:08 volumio go-librespot[28470]: time="2026-02-17T18:29:08+07:00" level=debug msg="app state loaded" Feb 17 18:29:08 volumio go-librespot[28470]: time="2026-02-17T18:29:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:09 volumio go-librespot[28470]: time="2026-02-17T18:29:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:29:09 volumio go-librespot[28470]: time="2026-02-17T18:29:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:29:09 volumio go-librespot[28470]: time="2026-02-17T18:29:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:29:09 volumio go-librespot[28470]: time="2026-02-17T18:29:09+07:00" level=info msg="zeroconf server listening on port 39703" Feb 17 18:29:09 volumio go-librespot[28470]: time="2026-02-17T18:29:09+07:00" level=debug msg="obtained new client token: AAAJz4CRo+7d/yApx7Q00n7K+b1knQre+j2akorDeJYOjaeCgpRb/zMgzXX37DoUfIzDXsR52Y7Ko8a4OlxTnUf3+BJoWw+1/yHR+t2Pav+BLDZ1ONhwGpl89ezJkjkv6zA6zqdy/fvCnTDibn7tUR6CXWxUmfiERqzzftJdWzG/CqQqejgZUBhElpMGaZ7N8KCGBtn1aZHYmVsWteEC534RS6SuVpJI6cxVV/5TI8pmVlkTmTU5yl6USg==" Feb 17 18:29:09 volumio go-librespot[28470]: time="2026-02-17T18:29:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:09 volumio go-librespot[28470]: time="2026-02-17T18:29:09+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:09 volumio go-librespot[28470]: time="2026-02-17T18:29:09+07:00" level=debug msg="completed challenge" Feb 17 18:29:10 volumio go-librespot[28470]: time="2026-02-17T18:29:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:11 volumio volumio[28376]: info: Loading plugin "ytmusic"... Feb 17 18:29:11 volumio volumio-remote-updater[25144]: [2026-02-17 18:29:11] [connect] Successful connection Feb 17 18:29:12 volumio volumio[28376]: info: Loading plugin "outputs"... Feb 17 18:29:12 volumio volumio[28376]: info: Loading plugin "albumart"... Feb 17 18:29:12 volumio volumio[28376]: info: Plugin example_plugin is not enabled Feb 17 18:29:12 volumio volumio[28376]: info: Loading plugin "inputs"... Feb 17 18:29:12 volumio volumio[28376]: info: Loading plugin "updater_comm"... Feb 17 18:29:12 volumio volumio[28376]: info: Plugin mpdemulation is not enabled Feb 17 18:29:12 volumio volumio[28376]: info: Loading plugin "rest_api"... Feb 17 18:29:12 volumio volumio[28376]: info: Loading plugin "websocket"... Feb 17 18:29:12 volumio volumio[28376]: info: Starting Socket.io Server version 1.7.4 Feb 17 18:29:12 volumio volumio[28376]: info: Loading plugin "RoonBridge"... Feb 17 18:29:12 volumio volumio[28376]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 18:29:12 volumio volumio[28376]: info: Loading i18n strings for locale en Feb 17 18:29:12 volumio volumio[28376]: Updating browse sources language Feb 17 18:29:12 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:29:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 17 18:29:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:13 volumio go-librespot[28502]: go-librespot daemon starting... Feb 17 18:29:13 volumio go-librespot[28503]: time="2026-02-17T18:29:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:13 volumio go-librespot[28503]: time="2026-02-17T18:29:13+07:00" level=debug msg="app state loaded" Feb 17 18:29:13 volumio go-librespot[28503]: time="2026-02-17T18:29:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 18:29:13 volumio volumio[28492]: Forking 3 albumart workers Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::initPlayerControls Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 18:29:13 volumio volumio[28376]: Express server listening on port 3000 Feb 17 18:29:13 volumio volumio[28376]: [Metrics] WebUI: 15s 947.43ms Feb 17 18:29:13 volumio volumio[28376]: info: CoreStateMachine::resetVolumioState Feb 17 18:29:13 volumio volumio[28376]: info: CoreStateMachine::getcurrentVolume Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 18:29:13 volumio sudo[28541]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 18:29:13 volumio sudo[28541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:13 volumio sudo[28541]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:13 volumio sudo[28543]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 18:29:13 volumio sudo[28543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:13 volumio sudo[28543]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:13 volumio volumio[28376]: info: Volumio Network Manager: Network status updated: 1 Feb 17 18:29:13 volumio go-librespot[28503]: time="2026-02-17T18:29:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:29:13 volumio go-librespot[28503]: time="2026-02-17T18:29:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:29:13 volumio go-librespot[28503]: time="2026-02-17T18:29:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:29:13 volumio go-librespot[28503]: time="2026-02-17T18:29:13+07:00" level=info msg="zeroconf server listening on port 35941" Feb 17 18:29:13 volumio volumio[28376]: info: VolumeController:: Volume=100 Mute =false Feb 17 18:29:13 volumio volumio[28376]: info: CoreStateMachine::pushState Feb 17 18:29:13 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 18:29:13 volumio volumio[28376]: info: CoreCommandRouter::volumioPushState Feb 17 18:29:14 volumio volumio[28376]: info: CoreStateMachine::updateTrackBlock Feb 17 18:29:14 volumio volumio[28376]: info: CorePlayQueue::getTrackBlock Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 18:29:14 volumio volumio-remote-updater[25144]: [2026-02-17 18:29:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771327751 101 Feb 17 18:29:14 volumio go-librespot[28503]: time="2026-02-17T18:29:14+07:00" level=debug msg="obtained new client token: AAA7lekSpAAUu15eJiNJEShN/s3n2vvohYneAVuUCoGgstdIcpLBfpYQvmFd+W/LYM5/ma+L9COn/kGThiwcpCoh/DYCryWkVEfyXtQ6iNGXTBHf69O3acbj4SeAJ31IqzFlFFgFG3/qVcMaXEZvPL5kG/LRrawa4kRl/QWt79/nFPdXrWvNyM594pZKORY54hPGsTVi2BwHj7rLYf4cMmqa+zXaTETuLdW/+avWmzA+kX0wm0UzPI8=" Feb 17 18:29:14 volumio volumio[28376]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:14 volumio volumio[28376]: info: Reloading queue from file Feb 17 18:29:14 volumio go-librespot[28503]: time="2026-02-17T18:29:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 18:29:14 volumio volumio[28376]: info: CoreStateMachine::setRepeat null single undefined Feb 17 18:29:14 volumio volumio[28376]: info: CoreStateMachine::pushState Feb 17 18:29:14 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::volumioPushState Feb 17 18:29:14 volumio volumio[28376]: info: CoreStateMachine::setRandom null Feb 17 18:29:14 volumio volumio[28376]: info: CoreStateMachine::pushState Feb 17 18:29:14 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::volumioPushState Feb 17 18:29:14 volumio go-librespot[28503]: time="2026-02-17T18:29:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 17 18:29:14 volumio volumio[28376]: info: Setting Device type: Raspberry PI Feb 17 18:29:14 volumio volumio[28376]: info: Completed loading Core Plugins Feb 17 18:29:14 volumio volumio[28376]: info: Preparing to generate the ALSA configuration file Feb 17 18:29:14 volumio go-librespot[28503]: time="2026-02-17T18:29:14+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:14 volumio go-librespot[28503]: time="2026-02-17T18:29:14+07:00" level=debug msg="completed challenge" Feb 17 18:29:14 volumio volumio[28376]: info: VolumeController:: Volume=100 Mute =false Feb 17 18:29:14 volumio volumio[28376]: info: CoreStateMachine::pushState Feb 17 18:29:14 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::volumioPushState Feb 17 18:29:14 volumio go-librespot[28503]: time="2026-02-17T18:29:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:14 volumio volumio[28376]: info: Asound.conf file unchanged, so no further update is needed Feb 17 18:29:14 volumio volumio[28376]: info: Output device has changed, restarting MPD Feb 17 18:29:14 volumio sudo[28560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 18:29:14 volumio sudo[28560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:14 volumio volumio[28376]: info: Output device has changed, restarting Shairport Sync Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:14 volumio sudo[28562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 18:29:14 volumio sudo[28562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:14 volumio sudo[28562]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:14 volumio sudo[28564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 18:29:14 volumio sudo[28564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:14 volumio volumio[28376]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 18:29:14 volumio sudo[28560]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:14 volumio volumio[28376]: info: ___________ START PLUGINS ___________ Feb 17 18:29:14 volumio volumio[28376]: info: ControllerMpd::onStart: Initializing MPD Feb 17 18:29:14 volumio volumio[28376]: info: Creating MPD Configuration file Feb 17 18:29:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 18:29:14 volumio volumio[28376]: info: [1771327754858] CoreMusicLibrary::Adding element Media Servers Feb 17 18:29:14 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:29:14 volumio sudo[28573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 18:29:14 volumio sudo[28573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:14 volumio sudo[28573]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:14 volumio volumio[28376]: info: UPNP Browser: Client initialized successfully Feb 17 18:29:14 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 18:29:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 18:29:14 volumio systemd[1]: mpd.service: Consumed 7.168s CPU time. Feb 17 18:29:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 18:29:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 18:29:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 18:29:14 volumio sudo[28575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 18:29:14 volumio sudo[28575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 18:29:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 18:29:15 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 18:29:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 18:29:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 18:29:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 18:29:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 18:29:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 18:29:15 volumio volumio[28376]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 18:29:15 volumio volumio[28376]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 18:29:15 volumio volumio[28376]: info: [1771327755253] CoreMusicLibrary::Adding element Last_100 Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 18:29:15 volumio volumio[28376]: info: [1771327755264] CoreMusicLibrary::Adding element Webradio Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 18:29:15 volumio volumio[28376]: info: Initializing BBC Radios Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:15 volumio volumio[28376]: info: Creating Spotify config file Feb 17 18:29:15 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:15 volumio sudo[28585]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 18:29:15 volumio sudo[28585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 18:29:15 volumio sudo[28585]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:16 volumio volumio[28376]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 18:29:16 volumio volumio[28376]: info: [1771327756482] CoreMusicLibrary::Adding element YouTube Music Feb 17 18:29:16 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:29:16 volumio volumio[28376]: Cannot find translation for source YouTube Music Feb 17 18:29:16 volumio volumio[28376]: info: Volumio Calling Home Feb 17 18:29:16 volumio sudo[28606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 18:29:16 volumio sudo[28606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:16 volumio volumio[28514]: Starting albumart workers Feb 17 18:29:16 volumio sudo[28606]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:16 volumio volumio[28510]: Starting albumart workers Feb 17 18:29:17 volumio volumio[28376]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 18:29:17 volumio volumio[28376]: info: Discovery: Found device Volumio Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::volumioGetState Feb 17 18:29:17 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:17 volumio volumio[28376]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 18:29:17 volumio volumio[28376]: info: Discovery: Found device Volumio Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::volumioGetState Feb 17 18:29:17 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:17 volumio volumio[28509]: Starting albumart workers Feb 17 18:29:17 volumio volumio[28376]: info: MPD Permissions set Feb 17 18:29:17 volumio volumio[28376]: info: MPD Permissions set Feb 17 18:29:17 volumio volumio[28376]: info: Upmpdcli Daemon Started Feb 17 18:29:17 volumio volumio[28376]: info: Volumio called home Feb 17 18:29:17 volumio volumio[28376]: info: Spotify config file written Feb 17 18:29:17 volumio sudo[28612]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 18:29:17 volumio sudo[28612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 17 18:29:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:17 volumio go-librespot[28614]: go-librespot daemon starting... Feb 17 18:29:17 volumio go-librespot[28615]: time="2026-02-17T18:29:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:17 volumio go-librespot[28615]: time="2026-02-17T18:29:17+07:00" level=debug msg="app state loaded" Feb 17 18:29:17 volumio go-librespot[28615]: time="2026-02-17T18:29:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:17 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 18:29:17 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 18:29:17 volumio volumio[28376]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 17 18:29:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio go-librespot[28621]: go-librespot daemon starting... Feb 17 18:29:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:17 volumio sudo[28612]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:17 volumio go-librespot[28623]: time="2026-02-17T18:29:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:17 volumio go-librespot[28623]: time="2026-02-17T18:29:17+07:00" level=debug msg="app state loaded" Feb 17 18:29:17 volumio go-librespot[28623]: time="2026-02-17T18:29:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:18 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:18 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:18 volumio volumio[28376]: info: No need to fix Spotify hosts Feb 17 18:29:18 volumio go-librespot[28623]: time="2026-02-17T18:29:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 18:29:18 volumio go-librespot[28623]: time="2026-02-17T18:29:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 18:29:18 volumio go-librespot[28623]: time="2026-02-17T18:29:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 18:29:18 volumio go-librespot[28623]: time="2026-02-17T18:29:18+07:00" level=info msg="zeroconf server listening on port 39821" Feb 17 18:29:18 volumio go-librespot[28623]: time="2026-02-17T18:29:18+07:00" level=debug msg="obtained new client token: AACOTy8R1IFTD58dHk9qM9hMfO/rTfMRGozpzDF15F3AVhSK0pJwt1AhzNYsTai6Db0PfoIspfO53S2X5xvRy/aeg0CFqSbiIpyFoxHJNrJhuo3JWvkYcwCZwQOGa8PW4d6aInmoQE5n45uLDEwg256QGHZ7bF4GU14PVaFaiXEpoRqn/P7MlyZneTFDXjzfWSIDtyucuwTwkNzug3xyTKa6hpV9vvVtYAacSJOlRcuTWmFFnLl9nI9kgA==" Feb 17 18:29:19 volumio go-librespot[28623]: time="2026-02-17T18:29:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:19 volumio go-librespot[28623]: time="2026-02-17T18:29:19+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:19 volumio go-librespot[28623]: time="2026-02-17T18:29:19+07:00" level=debug msg="completed challenge" Feb 17 18:29:19 volumio go-librespot[28623]: time="2026-02-17T18:29:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:19 volumio volumio[28376]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 18:29:19 volumio volumio[28376]: SPOTIFY: BQA2dN68BXQJO_NGI6ove5zQPVQ6_-dfDCuABgYiskUqOA_jjGChN2dRQFlg-Actf694neeHNbO2vU7ZYWrNMLAO4uL-dCLxpvoC6nhEAmlE9Qz1ZDVakdzEC0MyWgIU-2hvUP0xpo8WFRS04NiL_idkIywHM47b2lGC7tJ8vmeATXUX4bW2aL1f3W5jn9bwYLJEmM5FFLJYZkv-nUHNeBZPqpLFNTaKfiD3LdHVbzeCUIl4W6ha6fmkDXTYtuqXwoTP1dNv8tVsrBoBDRjlH0iI8Dowb35Pc7pVZHwt2cQqv7Ubi9IEpMdd Feb 17 18:29:19 volumio volumio[28376]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 18:29:19 volumio volumio[28376]: info: New Spotify access token = BQA2dN68BXQJO_NGI6ove5zQPVQ6_-dfDCuABgYiskUqOA_jjGChN2dRQFlg-Actf694neeHNbO2vU7ZYWrNMLAO4uL-dCLxpvoC6nhEAmlE9Qz1ZDVakdzEC0MyWgIU-2hvUP0xpo8WFRS04NiL_idkIywHM47b2lGC7tJ8vmeATXUX4bW2aL1f3W5jn9bwYLJEmM5FFLJYZkv-nUHNeBZPqpLFNTaKfiD3LdHVbzeCUIl4W6ha6fmkDXTYtuqXwoTP1dNv8tVsrBoBDRjlH0iI8Dowb35Pc7pVZHwt2cQqv7Ubi9IEpMdd Feb 17 18:29:19 volumio volumio[28376]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 18:29:19 volumio volumio[28376]: info: Starting Shairport Sync Feb 17 18:29:19 volumio volumio[28376]: info: Starting Shairport Sync Feb 17 18:29:19 volumio volumio[28376]: info: Starting Shairport Sync Feb 17 18:29:19 volumio sudo[28658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 18:29:19 volumio sudo[28658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:19 volumio sudo[28660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 18:29:19 volumio sudo[28660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:19 volumio sudo[28662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 18:29:19 volumio sudo[28662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 18:29:19 volumio volumio[28376]: info: CoreCommandRouter::volumioGetState Feb 17 18:29:19 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 18:29:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 18:29:19 volumio systemd[1]: shairport-sync.service: Consumed 2.371s CPU time. Feb 17 18:29:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 18:29:19 volumio sudo[28658]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:20 volumio sudo[28660]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:20 volumio sudo[28662]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:20 volumio volumio[28376]: info: Shairport-Sync Started Feb 17 18:29:20 volumio volumio[28376]: Error adding Membership: Error: addMembership EINVAL Feb 17 18:29:20 volumio volumio[28376]: info: Shairport-Sync Started Feb 17 18:29:20 volumio volumio[28376]: info: Shairport-Sync Started Feb 17 18:29:20 volumio volumio[28376]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 17 18:29:20 volumio volumio[28376]: info: Spotify Successfully logged in Feb 17 18:29:20 volumio volumio[28376]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 18:29:20 volumio volumio[28376]: info: [1771327760278] CoreMusicLibrary::Adding element Spotify Feb 17 18:29:20 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:29:20 volumio volumio[28376]: Cannot find translation for source YouTube Music Feb 17 18:29:20 volumio volumio[28376]: Cannot find translation for source Spotify Feb 17 18:29:20 volumio volumio[28376]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 18:29:20 volumio volumio[28376]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 18:29:21 volumio volumio[28376]: info: VolumeController:: Volume=100 Mute =false Feb 17 18:29:21 volumio volumio[28376]: info: CoreCommandRouter::volumioGetState Feb 17 18:29:21 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:21 volumio volumio[28376]: info: CoreStateMachine::pushState Feb 17 18:29:21 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:21 volumio volumio[28376]: info: CoreCommandRouter::volumioPushState Feb 17 18:29:22 volumio volumio[28376]: info: go-librespot daemon successfully initialized Feb 17 18:29:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 18:29:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:22 volumio go-librespot[28699]: go-librespot daemon starting... Feb 17 18:29:22 volumio go-librespot[28700]: time="2026-02-17T18:29:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:22 volumio go-librespot[28700]: time="2026-02-17T18:29:22+07:00" level=debug msg="app state loaded" Feb 17 18:29:22 volumio go-librespot[28700]: time="2026-02-17T18:29:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:22 volumio mpd[28604]: 2026-02-17T18:29:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 18:29:22 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 18:29:22 volumio sudo[28575]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:22 volumio sudo[28564]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:22 volumio volumio[28376]: error: MPD error: The expression evaluated to a falsy value: Feb 17 18:29:22 volumio volumio[28376]: assert.ok(self.idling) Feb 17 18:29:22 volumio volumio[28376]: error: The expression evaluated to a falsy value: Feb 17 18:29:22 volumio volumio[28376]: assert.ok(self.idling) Feb 17 18:29:22 volumio volumio[28376]: error: updateQueue error: null Feb 17 18:29:22 volumio volumio[28376]: info: MPD running with PID28604 Feb 17 18:29:22 volumio volumio[28376]: ,establishing connection Feb 17 18:29:23 volumio volumio[28376]: info: Completed starting Core Plugins Feb 17 18:29:23 volumio volumio[28376]: info: ------------------------------------------- Feb 17 18:29:23 volumio volumio[28376]: info: ----- MyVolumio plugins startup ---- Feb 17 18:29:23 volumio volumio[28376]: info: ------------------------------------------- Feb 17 18:29:23 volumio volumio[28376]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 18:29:23 volumio volumio[28376]: error: updateQueue error: null Feb 17 18:29:23 volumio go-librespot[28700]: time="2026-02-17T18:29:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:29:23 volumio go-librespot[28700]: time="2026-02-17T18:29:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:29:23 volumio go-librespot[28700]: time="2026-02-17T18:29:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:29:23 volumio go-librespot[28700]: time="2026-02-17T18:29:23+07:00" level=info msg="zeroconf server listening on port 44451" Feb 17 18:29:23 volumio go-librespot[28700]: time="2026-02-17T18:29:23+07:00" level=debug msg="obtained new client token: AACbtOunKbxV6njuRyi6CwasgKRNLqkX3OKhmZHL4IY3GsnDdzg/y3gw/mGcl7zqVkb76j5I1mQQ+eVzGimFLn3HkJQjolarW19Bum+n/sKzziRnxxfUpnz6wzrPa4hIVQy4E66xr3No8edN+SCIzHs7h+3tk4e0FrmQo4WCkvLABRN5ME5AXyXIUrVDAUVNVX4wBlylumzezAccuRIRMsvFMWljh3QxW+MpLGD8cHWp+kOHt0p+MT3H9w==" Feb 17 18:29:23 volumio go-librespot[28700]: time="2026-02-17T18:29:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:23 volumio go-librespot[28700]: time="2026-02-17T18:29:23+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:23 volumio go-librespot[28700]: time="2026-02-17T18:29:23+07:00" level=debug msg="completed challenge" Feb 17 18:29:23 volumio go-librespot[28700]: time="2026-02-17T18:29:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:25 volumio volumio[28376]: info: Initializing connection to go-librespot Websocket Feb 17 18:29:25 volumio volumio[28376]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 18:29:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 18:29:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:26 volumio go-librespot[28712]: go-librespot daemon starting... Feb 17 18:29:26 volumio go-librespot[28713]: time="2026-02-17T18:29:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:26 volumio go-librespot[28713]: time="2026-02-17T18:29:26+07:00" level=debug msg="app state loaded" Feb 17 18:29:26 volumio go-librespot[28713]: time="2026-02-17T18:29:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:27 volumio go-librespot[28713]: time="2026-02-17T18:29:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 18:29:27 volumio go-librespot[28713]: time="2026-02-17T18:29:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 18:29:27 volumio go-librespot[28713]: time="2026-02-17T18:29:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 18:29:27 volumio go-librespot[28713]: time="2026-02-17T18:29:27+07:00" level=info msg="zeroconf server listening on port 42495" Feb 17 18:29:27 volumio go-librespot[28713]: time="2026-02-17T18:29:27+07:00" level=debug msg="obtained new client token: AABoRTyiWeRstpq7Ctq+DRJUuANAV1gsPn6jor4vzShNi/8zCF/sOC3SS4hxvcjPX6s13pOB5nG3Yq9melUUugJHYeqoSfBAVC1I2c/oFjVNt376DZg0PS4RYXijHIzmCmqSvNl84oBRZA3nytBwiDzucsvd9/82he2c8Igtk8zdFDlhopvtIXQZLNoSblEPJKL4mgU+FWUk1FonSbeNKj25vFkAE3i586wRUjnpeD2nU91E+/CNYLXxyw==" Feb 17 18:29:27 volumio go-librespot[28713]: time="2026-02-17T18:29:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:27 volumio volumio[28376]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 18:29:27 volumio go-librespot[28713]: time="2026-02-17T18:29:27+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:27 volumio go-librespot[28713]: time="2026-02-17T18:29:27+07:00" level=debug msg="completed challenge" Feb 17 18:29:27 volumio go-librespot[28713]: time="2026-02-17T18:29:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:28 volumio volumio[28376]: info: Initializing connection to go-librespot Websocket Feb 17 18:29:28 volumio volumio[28376]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 18:29:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 18:29:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:31 volumio go-librespot[28720]: go-librespot daemon starting... Feb 17 18:29:31 volumio go-librespot[28721]: time="2026-02-17T18:29:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:31 volumio go-librespot[28721]: time="2026-02-17T18:29:31+07:00" level=debug msg="app state loaded" Feb 17 18:29:31 volumio go-librespot[28721]: time="2026-02-17T18:29:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:31 volumio volumio[28376]: info: Initializing connection to go-librespot Websocket Feb 17 18:29:31 volumio go-librespot[28721]: time="2026-02-17T18:29:31+07:00" level=debug msg="new websocket client" Feb 17 18:29:31 volumio volumio[28376]: info: Connection to go-librespot Websocket established Feb 17 18:29:31 volumio go-librespot[28721]: time="2026-02-17T18:29:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:29:31 volumio go-librespot[28721]: time="2026-02-17T18:29:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:29:31 volumio go-librespot[28721]: time="2026-02-17T18:29:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:29:31 volumio go-librespot[28721]: time="2026-02-17T18:29:31+07:00" level=info msg="zeroconf server listening on port 45421" Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 18:29:31 volumio volumio[28376]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 18:29:31 volumio volumio[28376]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 18:29:31 volumio volumio[28376]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 18:29:31 volumio volumio[28376]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 18:29:31 volumio volumio[28376]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 18:29:31 volumio volumio[28376]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 18:29:31 volumio volumio[28376]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 18:29:31 volumio volumio[28376]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 18:29:32 volumio go-librespot[28721]: time="2026-02-17T18:29:32+07:00" level=debug msg="obtained new client token: AABQ0c7VaNZv5swvFPJNNqp385DP8WKcu5N3yhMZPlJRw6y+REy+pbB3ltjc+5gTOYwu8G0alhox6LTnqIaaXwYfIwx5NquJ+pw6wEAh+XvePzrsplFQbcK8QFDRLXpKzX21Aup6y5rnmvZpLiXlqTfPczx7LFsyTVFHiVbt1Wywqiuj2ynGK/kKpZXnGNm0ivUrMok31Zc9oyg1FzT3RzVhE/s2Vsy0QptiZPe96Blluw3fw8i+XqdQAA==" Feb 17 18:29:32 volumio go-librespot[28721]: time="2026-02-17T18:29:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:32 volumio go-librespot[28721]: time="2026-02-17T18:29:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 17 18:29:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:33 volumio volumio[28376]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 18:29:33 volumio volumio[28376]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 18:29:33 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:33 volumio volumio[28376]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:33 volumio volumio[28376]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 18:29:33 volumio volumio[28376]: info: MyVolumio login type: Token Feb 17 18:29:33 volumio volumio[28376]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 18:29:33 volumio volumio[28376]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 18:29:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 17 18:29:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:35 volumio go-librespot[28745]: go-librespot daemon starting... Feb 17 18:29:35 volumio go-librespot[28746]: time="2026-02-17T18:29:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:35 volumio go-librespot[28746]: time="2026-02-17T18:29:35+07:00" level=debug msg="app state loaded" Feb 17 18:29:35 volumio go-librespot[28746]: time="2026-02-17T18:29:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:35 volumio volumio[28376]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 18:29:35 volumio volumio[28376]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 18:29:35 volumio volumio[28376]: info: Streaming services startup Feb 17 18:29:35 volumio volumio[28376]: info: Starting Streaming Daemon Feb 17 18:29:35 volumio volumio[28376]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 18:29:35 volumio sudo[28753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 18:29:35 volumio sudo[28753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:35 volumio sudo[28753]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:35 volumio volumio[28376]: info: Getting Spotify volume Feb 17 18:29:35 volumio volumio[28376]: info: Connection to go-librespot Websocket closed Feb 17 18:29:35 volumio volumio[28376]: error: Cannot start Volumio Streaming Daemon Feb 17 18:29:35 volumio volumio[28376]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 18:29:35 volumio volumio[28376]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 18:29:35 volumio go-librespot[28746]: time="2026-02-17T18:29:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:29:35 volumio go-librespot[28746]: time="2026-02-17T18:29:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:29:35 volumio go-librespot[28746]: time="2026-02-17T18:29:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:29:35 volumio go-librespot[28746]: time="2026-02-17T18:29:35+07:00" level=info msg="zeroconf server listening on port 40885" Feb 17 18:29:36 volumio volumio[28376]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 17 18:29:36 volumio volumio[28376]: info: CoreCommandRouter::volumioGetState Feb 17 18:29:36 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:36 volumio go-librespot[28746]: time="2026-02-17T18:29:36+07:00" level=debug msg="obtained new client token: AAAqTW2cqeHJRxqizkYSZWmnXx3UJz22kVJxpwO4I91lldEo30I31P12T0dyfgkjIT5KwRqH7nzuZP55YOFUnu/wOS7K3SPNL7T3AB3bkqd3VZU81uMvf4vUXAi6pRMU3H40QUejfnbocPGSJJZIKThPi8ksJZ4Wdzu3F/PdCk43ddyc1fR614ZVD5OdP+lygvE9vZUvC0Pt99KEh7azKIj4GiXfDilRMg0L3MyTq3uOWogW24wUvNA=" Feb 17 18:29:36 volumio volumio[28376]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 17 18:29:36 volumio volumio[28376]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 18:29:36 volumio volumio[28376]: SPOTIFY: VOLUMIO VOLUME 100 Feb 17 18:29:36 volumio volumio[28376]: info: Aligning Spotify Volume to Volumio Volume Feb 17 18:29:36 volumio volumio[28376]: info: CoreCommandRouter::volumioGetState Feb 17 18:29:36 volumio volumio[28376]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:36 volumio volumio[28376]: info: Setting Spotify Volume from Volumio: 100 Feb 17 18:29:36 volumio go-librespot[28746]: time="2026-02-17T18:29:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:36 volumio go-librespot[28746]: time="2026-02-17T18:29:36+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:36 volumio go-librespot[28746]: time="2026-02-17T18:29:36+07:00" level=debug msg="completed challenge" Feb 17 18:29:36 volumio go-librespot[28746]: time="2026-02-17T18:29:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:36 volumio volumio[28376]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 18:29:36 volumio volumio[28376]: Error: socket hang up Feb 17 18:29:36 volumio volumio[28376]: at connResetException (node:internal/errors:720:14) Feb 17 18:29:36 volumio volumio[28376]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 18:29:36 volumio volumio[28376]: at Socket.emit (node:events:526:35) Feb 17 18:29:36 volumio volumio[28376]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 18:29:36 volumio volumio[28376]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 18:29:36 volumio volumio[28376]: code: 'ECONNRESET', Feb 17 18:29:36 volumio volumio[28376]: response: undefined Feb 17 18:29:36 volumio volumio[28376]: } Feb 17 18:29:36 volumio volumio[28376]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 18:29:37 volumio sudo[28774]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 18:28' Feb 17 18:29:37 volumio sudo[28774]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:38 volumio sudo[28774]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 17 18:29:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:39 volumio go-librespot[28782]: go-librespot daemon starting... Feb 17 18:29:39 volumio go-librespot[28783]: time="2026-02-17T18:29:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:39 volumio go-librespot[28783]: time="2026-02-17T18:29:39+07:00" level=debug msg="app state loaded" Feb 17 18:29:39 volumio go-librespot[28783]: time="2026-02-17T18:29:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:39 volumio volumio-remote-updater[25144]: [2026-02-17 18:29:39] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 17 18:29:39 volumio volumio-remote-updater[25144]: [2026-02-17 18:29:39] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 17 18:29:39 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:39 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 18:29:39 volumio systemd[1]: volumio.service: Consumed 55.956s CPU time. Feb 17 18:29:39 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 18:29:39 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 18:29:39 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20708. Feb 17 18:29:39 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 18:29:39 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 18:29:39 volumio systemd[1]: volumio.service: Consumed 55.956s CPU time. Feb 17 18:29:39 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 18:29:39 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 18:29:40 volumio go-librespot[28783]: time="2026-02-17T18:29:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:29:40 volumio go-librespot[28783]: time="2026-02-17T18:29:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:29:40 volumio go-librespot[28783]: time="2026-02-17T18:29:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:29:40 volumio go-librespot[28783]: time="2026-02-17T18:29:40+07:00" level=info msg="zeroconf server listening on port 46849" Feb 17 18:29:40 volumio go-librespot[28783]: time="2026-02-17T18:29:40+07:00" level=debug msg="obtained new client token: AABhT9lbEqs96JAEb4plbVqocXmg4uylRaNgr8swlCkPKH5IJ7PU4uMzM/K83tgPIh0CItMAzaKKxj2GGZ0wi5r05dqik1E1bp7BgAnxSbyBDaiVrrKJYzXwrWP2bCiSf8LqCErm9Z4kaRcxwOv9GkjzUFDYon1K7qE8ZdKv21VFKCjGzoVspztYmjijBNomVJ+s2A5Y3oYBl01IIgRiDRFzo//CrqbIQT8YfjcPaXx76e4+1L9dt9TBgg==" Feb 17 18:29:40 volumio go-librespot[28783]: time="2026-02-17T18:29:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:40 volumio go-librespot[28783]: time="2026-02-17T18:29:40+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:40 volumio go-librespot[28783]: time="2026-02-17T18:29:40+07:00" level=debug msg="completed challenge" Feb 17 18:29:40 volumio go-librespot[28783]: time="2026-02-17T18:29:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:43 volumio volumio[28801]: info: ------------------------------------------- Feb 17 18:29:43 volumio volumio[28801]: info: ----- Volumio3 ---- Feb 17 18:29:43 volumio volumio[28801]: info: ------------------------------------------- Feb 17 18:29:43 volumio volumio[28801]: info: ----- System startup ---- Feb 17 18:29:43 volumio volumio[28801]: info: ------------------------------------------- Feb 17 18:29:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 17 18:29:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:44 volumio go-librespot[28824]: go-librespot daemon starting... Feb 17 18:29:44 volumio go-librespot[28825]: time="2026-02-17T18:29:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:44 volumio go-librespot[28825]: time="2026-02-17T18:29:44+07:00" level=debug msg="app state loaded" Feb 17 18:29:44 volumio go-librespot[28825]: time="2026-02-17T18:29:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:44 volumio volumio-remote-updater[25144]: [2026-02-17 18:29:44] [connect] Successful connection Feb 17 18:29:44 volumio go-librespot[28825]: time="2026-02-17T18:29:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 18:29:44 volumio go-librespot[28825]: time="2026-02-17T18:29:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 18:29:44 volumio go-librespot[28825]: time="2026-02-17T18:29:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 18:29:44 volumio go-librespot[28825]: time="2026-02-17T18:29:44+07:00" level=info msg="zeroconf server listening on port 38925" Feb 17 18:29:44 volumio volumio[28801]: info: MYVOLUMIO Environment detected Feb 17 18:29:45 volumio go-librespot[28825]: time="2026-02-17T18:29:45+07:00" level=debug msg="obtained new client token: AAAl9TYyWMJsgC6RSqm5GgwjpYfQYTdVSReUDqrZyvQwk92T9/YX1lIrnZoeNUPtJqAdhHx+CwAyTv4DznVVsOvd2gQKoEWAxdD/mt11J0niw6t0bNFCGhC34o8KXLAxssAeZf0zCh8mTeDqFdXqQZSy+nQ8Q+WBhmDt50xoBg7cuNezQ8iJCiM0SnyEzblQudERZiaBNvrt57J73GucMwmS2EKGp9d2ba27oGkGY/70fqIZs2jqhR8=" Feb 17 18:29:45 volumio volumio[28801]: info: Plugin folders cleanup Feb 17 18:29:45 volumio volumio[28801]: info: Scanning into folder /volumio/app/plugins/ Feb 17 18:29:45 volumio volumio[28801]: info: Scanning category audio_interface Feb 17 18:29:45 volumio volumio[28801]: info: Scanning category miscellanea Feb 17 18:29:45 volumio volumio[28801]: info: Scanning category music_service Feb 17 18:29:45 volumio volumio[28801]: info: Scanning category plugins.json Feb 17 18:29:45 volumio volumio[28801]: info: Scanning category system_controller Feb 17 18:29:45 volumio volumio[28801]: info: Scanning category user_interface Feb 17 18:29:45 volumio volumio[28801]: info: Scanning into folder /data/plugins/ Feb 17 18:29:45 volumio volumio[28801]: info: Scanning category music_service Feb 17 18:29:45 volumio volumio[28801]: info: Plugin folders cleanup completed Feb 17 18:29:45 volumio volumio[28801]: info: ------------------------------------------- Feb 17 18:29:45 volumio volumio[28801]: info: ----- Core plugins startup ---- Feb 17 18:29:45 volumio volumio[28801]: info: ------------------------------------------- Feb 17 18:29:45 volumio volumio[28801]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 18:29:45 volumio volumio[28801]: info: Adding plugin upnp to MyMusic Plugins Feb 17 18:29:45 volumio volumio[28801]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 18:29:45 volumio volumio[28801]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 18:29:45 volumio volumio[28801]: info: Loading plugins from folder /data/plugins/ Feb 17 18:29:45 volumio go-librespot[28825]: time="2026-02-17T18:29:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:45 volumio volumio[28801]: info: Loading plugin "system"... Feb 17 18:29:45 volumio volumio[28801]: info: Loading plugin "appearance"... Feb 17 18:29:45 volumio go-librespot[28825]: time="2026-02-17T18:29:45+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:45 volumio go-librespot[28825]: time="2026-02-17T18:29:45+07:00" level=debug msg="completed challenge" Feb 17 18:29:45 volumio go-librespot[28825]: time="2026-02-17T18:29:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:47 volumio volumio[28801]: info: Loading plugin "network"... Feb 17 18:29:47 volumio volumio[28801]: info: Refreshing Cached IP Addresses Feb 17 18:29:47 volumio sudo[28839]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 18:29:47 volumio sudo[28841]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 18:29:47 volumio sudo[28839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:47 volumio sudo[28841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:47 volumio volumio[28801]: info: Loading plugin "services"... Feb 17 18:29:47 volumio sudo[28841]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:47 volumio sudo[28839]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:47 volumio volumio[28801]: info: Loading plugin "alsa_controller"... Feb 17 18:29:47 volumio sudo[28848]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 18:29:47 volumio sudo[28848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:47 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 18:29:47 volumio volumio[28801]: info: Loading plugin "wizard"... Feb 17 18:29:47 volumio volumio[28801]: info: Loading plugin "networkfs"... Feb 17 18:29:47 volumio volumio[28801]: info: Starting Udev Watcher for removable devices Feb 17 18:29:47 volumio volumio[28801]: info: Ignoring mount for partition: boot Feb 17 18:29:47 volumio volumio[28801]: info: Ignoring mount for partition: volumio Feb 17 18:29:47 volumio volumio[28801]: info: Ignoring mount for partition: volumio_data Feb 17 18:29:47 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 18:29:47 volumio volumio[28801]: info: Loading plugin "volumio_command_line_client"... Feb 17 18:29:47 volumio volumio[28801]: info: Loading plugin "upnp"... Feb 17 18:29:47 volumio volumio[28801]: info: [1771327787507] Starting Upmpd Daemon Feb 17 18:29:47 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 18:29:47 volumio volumio[28801]: info: Loading plugin "my_music"... Feb 17 18:29:47 volumio volumio[28801]: info: Loading plugin "mpd"... Feb 17 18:29:48 volumio volumio[28801]: info: Loading plugin "upnp_browser"... Feb 17 18:29:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 17 18:29:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:48 volumio go-librespot[28872]: go-librespot daemon starting... Feb 17 18:29:48 volumio go-librespot[28873]: time="2026-02-17T18:29:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:48 volumio go-librespot[28873]: time="2026-02-17T18:29:48+07:00" level=debug msg="app state loaded" Feb 17 18:29:48 volumio go-librespot[28873]: time="2026-02-17T18:29:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:49 volumio go-librespot[28873]: time="2026-02-17T18:29:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:29:49 volumio go-librespot[28873]: time="2026-02-17T18:29:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:29:49 volumio go-librespot[28873]: time="2026-02-17T18:29:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:29:49 volumio go-librespot[28873]: time="2026-02-17T18:29:49+07:00" level=info msg="zeroconf server listening on port 45451" Feb 17 18:29:49 volumio go-librespot[28873]: time="2026-02-17T18:29:49+07:00" level=debug msg="obtained new client token: AADa5ZWroUceU6hFk7V0J/kB7EdD7aC8c24pNsuADh93k7hm1KMzJb8gkLELOMgzuXKT2pdBR1ak5IlhLQ3B6D/CQPStJJavUMZQkRH5hSe+cdFSoqV4neGrnrP3Kvo7Nkf4VUBTpcvNqwweOQ2mYaDlmt7zWwoDP1DBjpfwqsh5qwUoGlS7AKZNKWXQqxj/GqcwqsL6Nk2PH6Lk+oiz7eiwf6xc7/d1IJX+zO677RMd28v5g24602tWJQ==" Feb 17 18:29:49 volumio go-librespot[28873]: time="2026-02-17T18:29:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:49 volumio go-librespot[28873]: time="2026-02-17T18:29:49+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:49 volumio go-librespot[28873]: time="2026-02-17T18:29:49+07:00" level=debug msg="completed challenge" Feb 17 18:29:49 volumio go-librespot[28873]: time="2026-02-17T18:29:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:50 volumio sudo[28848]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:51 volumio volumio[28801]: info: Starting UPNP Browser Feb 17 18:29:51 volumio volumio[28801]: info: Loading plugin "alarm-clock"... Feb 17 18:29:51 volumio volumio[28801]: info: Loading plugin "airplay_emulation"... Feb 17 18:29:51 volumio volumio[28801]: info: Starting Shairport Sync Feb 17 18:29:51 volumio volumio[28801]: info: Loading plugin "last_100"... Feb 17 18:29:51 volumio volumio[28801]: info: Loading plugin "webradio"... Feb 17 18:29:51 volumio volumio[28801]: info: Loading plugin "i2s_dacs"... Feb 17 18:29:51 volumio volumio[28801]: info: Loading plugin "volumiodiscovery"... Feb 17 18:29:51 volumio volumio[28801]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 18:29:51 volumio volumio[28801]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 18:29:51 volumio node[28801]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 18:29:51 volumio volumio[28801]: *** WARNING *** For more information see Feb 17 18:29:51 volumio volumio[28801]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 18:29:51 volumio volumio[28801]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 18:29:51 volumio volumio[28801]: *** WARNING *** For more information see Feb 17 18:29:51 volumio node[28801]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 18:29:51 volumio node[28801]: *** WARNING *** For more information see Feb 17 18:29:51 volumio node[28801]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 18:29:51 volumio node[28801]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 18:29:51 volumio node[28801]: *** WARNING *** For more information see Feb 17 18:29:51 volumio volumio[28801]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 18:29:51 volumio volumio[28801]: info: Discovery: Started advertising with name: Volumio Feb 17 18:29:51 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 18:29:51 volumio volumio[28801]: info: Loading plugin "spop"... Feb 17 18:29:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 17 18:29:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:52 volumio go-librespot[28883]: go-librespot daemon starting... Feb 17 18:29:52 volumio go-librespot[28884]: time="2026-02-17T18:29:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:52 volumio go-librespot[28884]: time="2026-02-17T18:29:52+07:00" level=debug msg="app state loaded" Feb 17 18:29:52 volumio go-librespot[28884]: time="2026-02-17T18:29:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:53 volumio go-librespot[28884]: time="2026-02-17T18:29:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:29:53 volumio go-librespot[28884]: time="2026-02-17T18:29:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:29:53 volumio go-librespot[28884]: time="2026-02-17T18:29:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:29:53 volumio go-librespot[28884]: time="2026-02-17T18:29:53+07:00" level=info msg="zeroconf server listening on port 36703" Feb 17 18:29:53 volumio volumio[28801]: info: Loading plugin "ytcr"... Feb 17 18:29:53 volumio go-librespot[28884]: time="2026-02-17T18:29:53+07:00" level=debug msg="obtained new client token: AAChaHw+TXhtxJOX9+YyfTqRIKiqH642Vapi9ZVqtR/Vot4BTHs4XA0ki+fZC1S/VBC78XgQ4vhzhLNZyYXtPVMdND+SBM3t+qplZtwxy/bxgwbwjtmpHpGoqYFzMeKl6+Zbe7xpEODX3lUglPQy4SiE4pa9yJytRXuY9rz3/xi/uGzoQHd7BieMjRNYzHp6EEWWC8olySbihgHNFDPmSmlcbH0qFNNMi7hurF8A3hiJbISvrxhbwAyPnQ==" Feb 17 18:29:53 volumio go-librespot[28884]: time="2026-02-17T18:29:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:53 volumio go-librespot[28884]: time="2026-02-17T18:29:53+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:53 volumio go-librespot[28884]: time="2026-02-17T18:29:53+07:00" level=debug msg="completed challenge" Feb 17 18:29:53 volumio go-librespot[28884]: time="2026-02-17T18:29:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:56 volumio volumio[28801]: info: Loading plugin "ytmusic"... Feb 17 18:29:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 17 18:29:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:29:57 volumio go-librespot[28891]: go-librespot daemon starting... Feb 17 18:29:57 volumio go-librespot[28892]: time="2026-02-17T18:29:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:29:57 volumio go-librespot[28892]: time="2026-02-17T18:29:57+07:00" level=debug msg="app state loaded" Feb 17 18:29:57 volumio go-librespot[28892]: time="2026-02-17T18:29:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:29:57 volumio volumio-remote-updater[25144]: [2026-02-17 18:29:57] [connect] Successful connection Feb 17 18:29:57 volumio volumio[28801]: info: Loading plugin "outputs"... Feb 17 18:29:57 volumio volumio[28801]: info: Loading plugin "albumart"... Feb 17 18:29:57 volumio volumio[28801]: info: Plugin example_plugin is not enabled Feb 17 18:29:57 volumio volumio[28801]: info: Loading plugin "inputs"... Feb 17 18:29:57 volumio volumio[28801]: info: Loading plugin "updater_comm"... Feb 17 18:29:57 volumio volumio[28801]: info: Plugin mpdemulation is not enabled Feb 17 18:29:57 volumio volumio[28801]: info: Loading plugin "rest_api"... Feb 17 18:29:57 volumio volumio[28801]: info: Loading plugin "websocket"... Feb 17 18:29:57 volumio go-librespot[28892]: time="2026-02-17T18:29:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 18:29:57 volumio go-librespot[28892]: time="2026-02-17T18:29:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 18:29:57 volumio go-librespot[28892]: time="2026-02-17T18:29:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 18:29:57 volumio volumio[28801]: info: Starting Socket.io Server version 1.7.4 Feb 17 18:29:57 volumio volumio[28801]: info: Loading plugin "RoonBridge"... Feb 17 18:29:57 volumio go-librespot[28892]: time="2026-02-17T18:29:57+07:00" level=info msg="zeroconf server listening on port 38951" Feb 17 18:29:58 volumio go-librespot[28892]: time="2026-02-17T18:29:58+07:00" level=debug msg="obtained new client token: AACAFuvwxuHlxKJe+QkKP2szmhv/w5d6vdFxpVHjzKIU/cvGLRsrmhSu7bc7yefNnFEcA0gvcNn4cO9OgmaLU09hhHlBPtSZquU78yep48F3p9RvvBGNdsi5OFGm/Bbzcd0fpf6mP1pKUUM5gfQ15cbU4tVIKp3Gq59WVGREY1AJeuvk72EZTNIHozeQJuzntmGufUly2JQQF4BfsuAzC2/KVpaAS4TnhOTW3w1JkEKrNIYDVqFfkPE65Q==" Feb 17 18:29:58 volumio go-librespot[28892]: time="2026-02-17T18:29:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:29:58 volumio go-librespot[28892]: time="2026-02-17T18:29:58+07:00" level=debug msg="completed keyexchange" Feb 17 18:29:58 volumio go-librespot[28892]: time="2026-02-17T18:29:58+07:00" level=debug msg="completed challenge" Feb 17 18:29:58 volumio go-librespot[28892]: time="2026-02-17T18:29:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:29:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:29:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:29:58 volumio volumio[28801]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 18:29:58 volumio volumio[28801]: info: Loading i18n strings for locale en Feb 17 18:29:58 volumio volumio[28801]: Updating browse sources language Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:29:58 volumio volumio[28912]: Forking 3 albumart workers Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::initPlayerControls Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 18:29:58 volumio volumio[28801]: Express server listening on port 3000 Feb 17 18:29:58 volumio volumio[28801]: [Metrics] WebUI: 16s 114.48ms Feb 17 18:29:58 volumio volumio[28801]: info: CoreStateMachine::resetVolumioState Feb 17 18:29:58 volumio volumio[28801]: info: CoreStateMachine::getcurrentVolume Feb 17 18:29:58 volumio volumio[28801]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 18:29:58 volumio sudo[28959]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 18:29:58 volumio sudo[28959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:58 volumio sudo[28961]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 18:29:58 volumio sudo[28959]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:59 volumio sudo[28961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:59 volumio sudo[28961]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:59 volumio volumio[28801]: info: Volumio Network Manager: Network status updated: 1 Feb 17 18:29:59 volumio volumio[28801]: info: VolumeController:: Volume=100 Mute =false Feb 17 18:29:59 volumio volumio[28801]: info: CoreStateMachine::pushState Feb 17 18:29:59 volumio volumio[28801]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:59 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 18:29:59 volumio volumio[28801]: info: CoreCommandRouter::volumioPushState Feb 17 18:29:59 volumio volumio[28801]: info: CoreStateMachine::updateTrackBlock Feb 17 18:29:59 volumio volumio[28801]: info: CorePlayQueue::getTrackBlock Feb 17 18:29:59 volumio volumio[28801]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 18:29:59 volumio volumio-remote-updater[25144]: [2026-02-17 18:29:59] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771327797 101 Feb 17 18:29:59 volumio volumio[28801]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 17 18:29:59 volumio volumio[28801]: info: Reloading queue from file Feb 17 18:29:59 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:59 volumio volumio[28801]: info: CoreStateMachine::setRepeat null single undefined Feb 17 18:29:59 volumio volumio[28801]: info: CoreStateMachine::pushState Feb 17 18:29:59 volumio volumio[28801]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:59 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 18:29:59 volumio volumio[28801]: info: CoreCommandRouter::volumioPushState Feb 17 18:29:59 volumio volumio[28801]: info: CoreStateMachine::setRandom null Feb 17 18:29:59 volumio volumio[28801]: info: CoreStateMachine::pushState Feb 17 18:29:59 volumio volumio[28801]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:59 volumio volumio[28801]: info: CoreCommandRouter::volumioPushState Feb 17 18:29:59 volumio volumio[28801]: info: Setting Device type: Raspberry PI Feb 17 18:29:59 volumio volumio[28801]: info: Completed loading Core Plugins Feb 17 18:29:59 volumio volumio[28801]: info: Preparing to generate the ALSA configuration file Feb 17 18:29:59 volumio volumio[28801]: info: VolumeController:: Volume=100 Mute =false Feb 17 18:29:59 volumio volumio[28801]: info: CoreStateMachine::pushState Feb 17 18:29:59 volumio volumio[28801]: info: CorePlayQueue::getTrack 0 Feb 17 18:29:59 volumio volumio[28801]: info: CoreCommandRouter::volumioPushState Feb 17 18:29:59 volumio volumio[28801]: info: Asound.conf file unchanged, so no further update is needed Feb 17 18:29:59 volumio volumio[28801]: info: Output device has changed, restarting MPD Feb 17 18:29:59 volumio sudo[28976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 18:29:59 volumio sudo[28976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:59 volumio volumio[28801]: info: Output device has changed, restarting Shairport Sync Feb 17 18:29:59 volumio sudo[28976]: pam_unix(sudo:session): session closed for user root Feb 17 18:29:59 volumio sudo[28981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 18:29:59 volumio sudo[28981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:29:59 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:29:59 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:29:59 volumio sudo[28979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 18:29:59 volumio sudo[28979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:30:00 volumio sudo[28979]: pam_unix(sudo:session): session closed for user root Feb 17 18:30:00 volumio volumio[28801]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 18:30:00 volumio volumio[28801]: info: ___________ START PLUGINS ___________ Feb 17 18:30:00 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 18:30:00 volumio volumio[28801]: info: ControllerMpd::onStart: Initializing MPD Feb 17 18:30:00 volumio volumio[28801]: info: Creating MPD Configuration file Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 18:30:00 volumio volumio[28801]: info: [1771327800155] CoreMusicLibrary::Adding element Media Servers Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:30:00 volumio volumio[28801]: info: UPNP Browser: Client initialized successfully Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:30:00 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 18:30:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 18:30:00 volumio sudo[28989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 18:30:00 volumio systemd[1]: mpd.service: Consumed 7.197s CPU time. Feb 17 18:30:00 volumio sudo[28989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:30:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 18:30:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 18:30:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 18:30:00 volumio sudo[28989]: pam_unix(sudo:session): session closed for user root Feb 17 18:30:00 volumio sudo[28991]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 18:30:00 volumio sudo[28991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:30:00 volumio volumio[28801]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:30:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 18:30:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 18:30:00 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 18:30:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 18:30:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 18:30:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 18:30:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 18:30:00 volumio volumio[28801]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 18:30:00 volumio volumio[28801]: info: [1771327800476] CoreMusicLibrary::Adding element Last_100 Feb 17 18:30:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 18:30:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 18:30:00 volumio volumio[28801]: info: [1771327800497] CoreMusicLibrary::Adding element Webradio Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 18:30:00 volumio volumio[28801]: info: Initializing BBC Radios Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:30:00 volumio volumio[28801]: info: Creating Spotify config file Feb 17 18:30:00 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:00 volumio sudo[29006]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 18:30:00 volumio sudo[29006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 18:30:00 volumio sudo[29006]: pam_unix(sudo:session): session closed for user root Feb 17 18:30:01 volumio volumio[28926]: Starting albumart workers Feb 17 18:30:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 17 18:30:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:30:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:30:01 volumio go-librespot[29023]: go-librespot daemon starting... Feb 17 18:30:01 volumio volumio[28801]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 18:30:01 volumio volumio[28801]: info: [1771327801784] CoreMusicLibrary::Adding element YouTube Music Feb 17 18:30:01 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:30:01 volumio volumio[28801]: Cannot find translation for source YouTube Music Feb 17 18:30:01 volumio volumio[28801]: info: Volumio Calling Home Feb 17 18:30:01 volumio go-librespot[29024]: time="2026-02-17T18:30:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:30:01 volumio sudo[29031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 18:30:01 volumio sudo[29031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:30:02 volumio sudo[29031]: pam_unix(sudo:session): session closed for user root Feb 17 18:30:02 volumio volumio[28925]: Starting albumart workers Feb 17 18:30:02 volumio volumio[28924]: Starting albumart workers Feb 17 18:30:02 volumio go-librespot[29024]: time="2026-02-17T18:30:02+07:00" level=info msg="zeroconf server listening on port 44785" Feb 17 18:30:02 volumio volumio[28801]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 18:30:02 volumio volumio[28801]: info: Discovery: Found device Volumio Feb 17 18:30:02 volumio volumio[28801]: info: CoreCommandRouter::volumioGetState Feb 17 18:30:02 volumio volumio[28801]: info: CorePlayQueue::getTrack 0 Feb 17 18:30:03 volumio volumio[28801]: info: MPD Permissions set Feb 17 18:30:03 volumio volumio[28801]: info: MPD Permissions set Feb 17 18:30:03 volumio volumio[28801]: info: Upmpdcli Daemon Started Feb 17 18:30:03 volumio volumio[28801]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 18:30:03 volumio volumio[28801]: info: Discovery: Found device Volumio Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::volumioGetState Feb 17 18:30:03 volumio volumio[28801]: info: CorePlayQueue::getTrack 0 Feb 17 18:30:03 volumio volumio[28801]: info: Volumio called home Feb 17 18:30:03 volumio volumio[28801]: info: Spotify config file written Feb 17 18:30:03 volumio volumio[28801]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 17 18:30:03 volumio sudo[29039]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 18:30:03 volumio sudo[29039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 18:30:03 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 18:30:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio go-librespot[29047]: go-librespot daemon starting... Feb 17 18:30:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:30:03 volumio sudo[29039]: pam_unix(sudo:session): session closed for user root Feb 17 18:30:03 volumio go-librespot[29052]: time="2026-02-17T18:30:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:30:03 volumio go-librespot[29052]: time="2026-02-17T18:30:03+07:00" level=debug msg="app state loaded" Feb 17 18:30:03 volumio go-librespot[29052]: time="2026-02-17T18:30:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 18:30:03 volumio volumio[28801]: info: No need to fix Spotify hosts Feb 17 18:30:04 volumio go-librespot[29052]: time="2026-02-17T18:30:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 18:30:04 volumio go-librespot[29052]: time="2026-02-17T18:30:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 18:30:04 volumio go-librespot[29052]: time="2026-02-17T18:30:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 18:30:04 volumio go-librespot[29052]: time="2026-02-17T18:30:04+07:00" level=info msg="zeroconf server listening on port 39087" Feb 17 18:30:04 volumio go-librespot[29052]: time="2026-02-17T18:30:04+07:00" level=debug msg="obtained new client token: AAAGz3nxIJu1YHSeVOF6ZfByOJ26LKabUm5uRjGE0kEfLrxoLp5ocQUXvosfd3MUuzo1oyIOumet5OIcWdML1ZVCx4dBi1IeTgNOS9qnxYMub+TztEn0ynky5T1/yJ3wsByUo0DoojTommmWOmgJpDGdlLWuxLqXGlSCSXp6Ur/JbEwZ+VtDIp6ham7i1G/Fq9MyGcB2anRI29Vrrl4EjarjQuazt/bUr2gScg5byyFrjX+RdQKoMhLk4g==" Feb 17 18:30:04 volumio go-librespot[29052]: time="2026-02-17T18:30:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:30:04 volumio go-librespot[29052]: time="2026-02-17T18:30:04+07:00" level=debug msg="completed keyexchange" Feb 17 18:30:04 volumio go-librespot[29052]: time="2026-02-17T18:30:04+07:00" level=debug msg="completed challenge" Feb 17 18:30:04 volumio go-librespot[29052]: time="2026-02-17T18:30:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:30:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:30:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:30:04 volumio volumio[28801]: info: Starting Shairport Sync Feb 17 18:30:04 volumio volumio[28801]: info: Starting Shairport Sync Feb 17 18:30:04 volumio volumio[28801]: info: Starting Shairport Sync Feb 17 18:30:04 volumio sudo[29080]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 18:30:04 volumio sudo[29080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:30:05 volumio sudo[29083]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 18:30:05 volumio sudo[29083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:30:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 18:30:05 volumio sudo[29085]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 18:30:05 volumio sudo[29085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 18:30:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 18:30:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 18:30:05 volumio systemd[1]: shairport-sync.service: Consumed 2.289s CPU time. Feb 17 18:30:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 18:30:05 volumio volumio[28801]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 18:30:05 volumio volumio[28801]: SPOTIFY: BQCtI_e1QAHxsHvfg32R5m6DMswlRixim4GT88lmYCFUP5UbvJOv2vOvdWJ0R6ep8ft5yvu1-dmGU86r8E1UOR67K5gwBX42R9o1Mpy3BpnmkVb8Uu1GEIai4Q12YA9cupX0eKoD0-YBzgzouFLIj3iSepLAF3Z6pYvKJAShW-FapozRAIDyUzoRqUyaATPTfT09OEBU3CcttpbKPw6B0UTO2i0dQUTadRnnjs7YtjFpU-8MmFw-BeRVby5LPmECzbQ1x3ZThhlnmwqoC3dJAB5ymmDELu8KJtwDr2w9Yp6vDUjpBUS2NHwT Feb 17 18:30:05 volumio volumio[28801]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 18:30:05 volumio sudo[29080]: pam_unix(sudo:session): session closed for user root Feb 17 18:30:05 volumio volumio[28801]: info: New Spotify access token = BQCtI_e1QAHxsHvfg32R5m6DMswlRixim4GT88lmYCFUP5UbvJOv2vOvdWJ0R6ep8ft5yvu1-dmGU86r8E1UOR67K5gwBX42R9o1Mpy3BpnmkVb8Uu1GEIai4Q12YA9cupX0eKoD0-YBzgzouFLIj3iSepLAF3Z6pYvKJAShW-FapozRAIDyUzoRqUyaATPTfT09OEBU3CcttpbKPw6B0UTO2i0dQUTadRnnjs7YtjFpU-8MmFw-BeRVby5LPmECzbQ1x3ZThhlnmwqoC3dJAB5ymmDELu8KJtwDr2w9Yp6vDUjpBUS2NHwT Feb 17 18:30:05 volumio volumio[28801]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 18:30:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 18:30:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 18:30:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 18:30:05 volumio volumio[28801]: info: CoreCommandRouter::volumioGetState Feb 17 18:30:05 volumio volumio[28801]: info: CorePlayQueue::getTrack 0 Feb 17 18:30:05 volumio volumio[28801]: info: Shairport-Sync Started Feb 17 18:30:05 volumio volumio[28801]: Error adding Membership: Error: addMembership EINVAL Feb 17 18:30:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 18:30:05 volumio sudo[29083]: pam_unix(sudo:session): session closed for user root Feb 17 18:30:05 volumio sudo[29085]: pam_unix(sudo:session): session closed for user root Feb 17 18:30:05 volumio volumio[28801]: info: Shairport-Sync Started Feb 17 18:30:05 volumio volumio[28801]: info: Shairport-Sync Started Feb 17 18:30:05 volumio volumio[28801]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 17 18:30:05 volumio volumio[28801]: info: Spotify Successfully logged in Feb 17 18:30:05 volumio volumio[28801]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 18:30:05 volumio volumio[28801]: info: [1771327805886] CoreMusicLibrary::Adding element Spotify Feb 17 18:30:05 volumio volumio[28801]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 18:30:05 volumio volumio[28801]: Cannot find translation for source YouTube Music Feb 17 18:30:05 volumio volumio[28801]: Cannot find translation for source Spotify Feb 17 18:30:06 volumio volumio[28801]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 18:30:06 volumio volumio[28801]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 18:30:06 volumio volumio[28801]: info: VolumeController:: Volume=100 Mute =false Feb 17 18:30:06 volumio volumio[28801]: info: CoreCommandRouter::volumioGetState Feb 17 18:30:06 volumio volumio[28801]: info: CorePlayQueue::getTrack 0 Feb 17 18:30:06 volumio volumio[28801]: info: CoreStateMachine::pushState Feb 17 18:30:06 volumio volumio[28801]: info: CorePlayQueue::getTrack 0 Feb 17 18:30:06 volumio volumio[28801]: info: CoreCommandRouter::volumioPushState Feb 17 18:30:07 volumio volumio[28801]: info: go-librespot daemon successfully initialized Feb 17 18:30:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 18:30:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:30:08 volumio mpd[29021]: 2026-02-17T18:30:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 18:30:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:30:08 volumio go-librespot[29121]: go-librespot daemon starting... Feb 17 18:30:08 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 18:30:08 volumio sudo[28981]: pam_unix(sudo:session): session closed for user root Feb 17 18:30:08 volumio sudo[28991]: pam_unix(sudo:session): session closed for user root Feb 17 18:30:08 volumio go-librespot[29124]: time="2026-02-17T18:30:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:30:08 volumio go-librespot[29124]: time="2026-02-17T18:30:08+07:00" level=debug msg="app state loaded" Feb 17 18:30:08 volumio go-librespot[29124]: time="2026-02-17T18:30:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:30:08 volumio volumio[28801]: error: MPD error: The expression evaluated to a falsy value: Feb 17 18:30:08 volumio volumio[28801]: assert.ok(self.idling) Feb 17 18:30:08 volumio volumio[28801]: error: The expression evaluated to a falsy value: Feb 17 18:30:08 volumio volumio[28801]: assert.ok(self.idling) Feb 17 18:30:08 volumio volumio[28801]: error: updateQueue error: null Feb 17 18:30:08 volumio volumio[28801]: info: MPD running with PID29021 Feb 17 18:30:08 volumio volumio[28801]: ,establishing connection Feb 17 18:30:08 volumio volumio[28801]: info: Completed starting Core Plugins Feb 17 18:30:08 volumio volumio[28801]: info: ------------------------------------------- Feb 17 18:30:08 volumio volumio[28801]: info: ----- MyVolumio plugins startup ---- Feb 17 18:30:08 volumio volumio[28801]: info: ------------------------------------------- Feb 17 18:30:08 volumio volumio[28801]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 18:30:08 volumio volumio[28801]: error: updateQueue error: null Feb 17 18:30:08 volumio go-librespot[29124]: time="2026-02-17T18:30:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 18:30:08 volumio go-librespot[29124]: time="2026-02-17T18:30:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 18:30:08 volumio go-librespot[29124]: time="2026-02-17T18:30:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 18:30:08 volumio go-librespot[29124]: time="2026-02-17T18:30:08+07:00" level=info msg="zeroconf server listening on port 46875" Feb 17 18:30:08 volumio go-librespot[29124]: time="2026-02-17T18:30:08+07:00" level=debug msg="obtained new client token: AACIhlCSbSyLH6g0cRhTzABn3P5x53bR+Skv/Ah4/q8vJm9yM9q+Ilf3zz8PcO7RrqOwhI8dte4QY7ol3eRrtRuVjOp3VD2r8aVKhD2EzyUZ4bgjzeuLztPPFkp92uDdPUaQlsuHns33Nh10mZgLkhPLRgyh1S8We2LyZwoYU4yaBeTnKJxYUehp9hd+P3JMrdCquv/p8mChRgJ/ub0TfSLm99ZjirS7XUSVQGSfqeeF7EgtOIrYR2pjfQ==" Feb 17 18:30:09 volumio go-librespot[29124]: time="2026-02-17T18:30:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:30:09 volumio go-librespot[29124]: time="2026-02-17T18:30:09+07:00" level=debug msg="completed keyexchange" Feb 17 18:30:09 volumio go-librespot[29124]: time="2026-02-17T18:30:09+07:00" level=debug msg="completed challenge" Feb 17 18:30:09 volumio go-librespot[29124]: time="2026-02-17T18:30:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:30:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:30:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:30:10 volumio volumio[28801]: info: Initializing connection to go-librespot Websocket Feb 17 18:30:10 volumio volumio[28801]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 18:30:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 18:30:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:30:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:30:13 volumio go-librespot[29135]: go-librespot daemon starting... Feb 17 18:30:13 volumio go-librespot[29136]: time="2026-02-17T18:30:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:30:13 volumio go-librespot[29136]: time="2026-02-17T18:30:13+07:00" level=debug msg="app state loaded" Feb 17 18:30:13 volumio go-librespot[29136]: time="2026-02-17T18:30:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:30:13 volumio volumio[28801]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 18:30:13 volumio go-librespot[29136]: time="2026-02-17T18:30:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:30:13 volumio go-librespot[29136]: time="2026-02-17T18:30:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:30:13 volumio go-librespot[29136]: time="2026-02-17T18:30:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:30:13 volumio go-librespot[29136]: time="2026-02-17T18:30:13+07:00" level=info msg="zeroconf server listening on port 39695" Feb 17 18:30:13 volumio volumio[28801]: info: Initializing connection to go-librespot Websocket Feb 17 18:30:13 volumio go-librespot[29136]: time="2026-02-17T18:30:13+07:00" level=debug msg="obtained new client token: AADIDKkHn9G5F+ZM54WDlwi+HxPf/Bi/3mhOgKsifpbPhu6qarQKqbltJfeghRoRuaibVmezQHFAHf8npZ836TJc22v/DC1KkTyWSLN0viC19gBVvj89Tj4XAlMteXj6M0wa0t/O5qiS18DhSa1cJ66mIkVurm6dAo6e+vYNEgy6CVXgksH+Y64SP81HyLaU1UTK0LWYtnDaI9Es8kFxzAGeMx31sUQ0XR2wVnm6+fX2NbiqES2qeA8ngw==" Feb 17 18:30:13 volumio go-librespot[29136]: time="2026-02-17T18:30:13+07:00" level=debug msg="new websocket client" Feb 17 18:30:13 volumio volumio[28801]: info: Connection to go-librespot Websocket established Feb 17 18:30:14 volumio go-librespot[29136]: time="2026-02-17T18:30:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:30:14 volumio go-librespot[29136]: time="2026-02-17T18:30:14+07:00" level=debug msg="completed keyexchange" Feb 17 18:30:14 volumio go-librespot[29136]: time="2026-02-17T18:30:14+07:00" level=debug msg="completed challenge" Feb 17 18:30:14 volumio go-librespot[29136]: time="2026-02-17T18:30:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:30:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:30:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:30:14 volumio volumio[28801]: info: Connection to go-librespot Websocket closed Feb 17 18:30:16 volumio volumio[28801]: info: Getting Spotify volume Feb 17 18:30:16 volumio volumio[28801]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 18:30:17 volumio volumio[28801]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 18:30:17 volumio volumio[28801]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 18:30:17 volumio volumio[28801]: errno: -111, Feb 17 18:30:17 volumio volumio[28801]: code: 'ECONNREFUSED', Feb 17 18:30:17 volumio volumio[28801]: syscall: 'connect', Feb 17 18:30:17 volumio volumio[28801]: address: '127.0.0.1', Feb 17 18:30:17 volumio volumio[28801]: port: 9879, Feb 17 18:30:17 volumio volumio[28801]: response: undefined Feb 17 18:30:17 volumio volumio[28801]: } Feb 17 18:30:17 volumio volumio[28801]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 18:30:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 18:30:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:30:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 18:30:17 volumio go-librespot[29155]: go-librespot daemon starting... Feb 17 18:30:17 volumio go-librespot[29156]: time="2026-02-17T18:30:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 18:30:17 volumio go-librespot[29156]: time="2026-02-17T18:30:17+07:00" level=debug msg="app state loaded" Feb 17 18:30:17 volumio go-librespot[29156]: time="2026-02-17T18:30:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 18:30:17 volumio go-librespot[29156]: time="2026-02-17T18:30:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 18:30:17 volumio go-librespot[29156]: time="2026-02-17T18:30:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 18:30:17 volumio go-librespot[29156]: time="2026-02-17T18:30:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 18:30:17 volumio go-librespot[29156]: time="2026-02-17T18:30:17+07:00" level=info msg="zeroconf server listening on port 42019" Feb 17 18:30:18 volumio go-librespot[29156]: time="2026-02-17T18:30:18+07:00" level=debug msg="obtained new client token: AADV7UnLkEC8nNW7Ei1trn4UvYFA1DG2R5leNJaxKLKcBwQ7WVmRLB6WT2V6VK04JNaGii4uFI41n/8oRQNWQTyWKDf2ouussA+mRxsYwvAbgihkLojB5r6k8RenEhks2fONAwHN52Qiym6gyVqRGLaUXk+r7oTQWD9hzVJ/vIHV18q/iT5snyHkrmBNHBiELpoyAPYslKJZRiYS+Lv8iLHddQmWECjsdpkZJhTy4m891+7/bCRe+EI=" Feb 17 18:30:18 volumio go-librespot[29156]: time="2026-02-17T18:30:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 18:30:18 volumio go-librespot[29156]: time="2026-02-17T18:30:18+07:00" level=debug msg="completed keyexchange" Feb 17 18:30:18 volumio go-librespot[29156]: time="2026-02-17T18:30:18+07:00" level=debug msg="completed challenge" Feb 17 18:30:18 volumio go-librespot[29156]: time="2026-02-17T18:30:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 18:30:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 18:30:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 18:30:18 volumio sudo[29179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 18:29' Feb 17 18:30:18 volumio sudo[29179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"