Feb 12 23:23:00 volumio volumio[17693]: info: Initializing connection to go-librespot Websocket
Feb 12 23:23:00 volumio go-librespot[18030]: time="2026-02-12T23:23:00+07:00" level=debug msg="new websocket client"
Feb 12 23:23:00 volumio volumio[17693]: info: Connection to go-librespot Websocket established
Feb 12 23:23:00 volumio go-librespot[18030]: time="2026-02-12T23:23: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 23:23:00 volumio go-librespot[18030]: time="2026-02-12T23:23:00+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 12 23:23:00 volumio go-librespot[18030]: time="2026-02-12T23:23:00+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 12 23:23:00 volumio go-librespot[18030]: time="2026-02-12T23:23:00+07:00" level=info msg="zeroconf server listening on port 45289"
Feb 12 23:23:00 volumio go-librespot[18030]: time="2026-02-12T23:23:00+07:00" level=debug msg="obtained new client token: AABfGRdL7LB4I/aDT5sLkq6qroX7RtMENvDET/iJurtDPKcukaoajPDpnBdhSLitM7XSaviPA2lUplVpIoE6Y9Rh2xdYUWI0aTVpJ8aR2061aaKQJsE5bx2Nxq4CeQG3BeQ+hQYJebgTlkaFjQQhFwN83WAJLK2Mp6NShz0d1QTkGRf27vaYYXINnNlsOpcaRiYjxAT3Ef1g8K94CCoF0N4iMNMnA27WqSCKNBYbDuX902LkSIM/3Txxng=="
Feb 12 23:23:00 volumio go-librespot[18030]: time="2026-02-12T23:23:00+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 12 23:23:00 volumio go-librespot[18030]: time="2026-02-12T23:23:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 12 23:23:00 volumio go-librespot[18030]: time="2026-02-12T23:23:00+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 12 23:23:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:00 volumio volumio[17693]: info: Connection to go-librespot Websocket closed
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 12 23:23:02 volumio volumio[17693]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 12 23:23:02 volumio volumio[17693]: info: Adding plugin multiroom to MyMusic Plugins
Feb 12 23:23:02 volumio volumio[17693]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 12 23:23:02 volumio volumio[17693]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 12 23:23:02 volumio volumio[17693]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 12 23:23:02 volumio volumio[17693]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 12 23:23:02 volumio volumio[17693]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 12 23:23:02 volumio volumio[17693]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 12 23:23:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 12 23:23:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:04 volumio go-librespot[18051]: go-librespot daemon starting...
Feb 12 23:23:04 volumio go-librespot[18052]: time="2026-02-12T23:23:04+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:04 volumio go-librespot[18052]: time="2026-02-12T23:23:04+07:00" level=debug msg="app state loaded"
Feb 12 23:23:04 volumio go-librespot[18052]: time="2026-02-12T23:23:04+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:04 volumio volumio[17693]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 12 23:23:04 volumio volumio[17693]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 12 23:23:04 volumio volumio[17693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:04 volumio volumio[17693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:04 volumio volumio[17693]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 12 23:23:04 volumio volumio[17693]: info: MyVolumio login type: Token
Feb 12 23:23:04 volumio volumio[17693]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 12 23:23:04 volumio volumio[17693]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 12 23:23:04 volumio go-librespot[18052]: time="2026-02-12T23:23: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 12 23:23:04 volumio go-librespot[18052]: time="2026-02-12T23:23: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 12 23:23:04 volumio go-librespot[18052]: time="2026-02-12T23:23: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 12 23:23:04 volumio go-librespot[18052]: time="2026-02-12T23:23:04+07:00" level=info msg="zeroconf server listening on port 45415"
Feb 12 23:23:04 volumio go-librespot[18052]: time="2026-02-12T23:23:04+07:00" level=debug msg="obtained new client token: AADcEf/z1KkS2hr3bbP038kwEhoPTA91vWmDgJ16nhwgHsxKKkgzBl/ap8xXhEvXzw5oWDjY2e/WZIFx8JbohnoYUKpEVxrGoyC0UXoN3CUCbDCbvQgjnnFAPB9ckG4iUv6S8VRZUf7bHeRliCEmsKud6cTNcYQ2lEdFYJ82E/czMjlEhd4x5QJFW4KLT26iM+khAh3ixC/NBRLAfc3eUkHbyTK6t51zdBmYctb1j57IC7yNa3SZnYhf4Q=="
Feb 12 23:23:05 volumio go-librespot[18052]: time="2026-02-12T23:23:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:05 volumio go-librespot[18052]: time="2026-02-12T23:23:05+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 12 23:23:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:06 volumio volumio[17693]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 12 23:23:06 volumio volumio[17693]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 12 23:23:06 volumio volumio[17693]: info: Streaming services startup
Feb 12 23:23:06 volumio volumio[17693]: info: Starting Streaming Daemon
Feb 12 23:23:06 volumio sudo[18062]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 23:23:06 volumio sudo[18062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:06 volumio volumio[17693]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 12 23:23:06 volumio sudo[18062]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:06 volumio volumio[17693]: info: Getting Spotify volume
Feb 12 23:23:06 volumio volumio[17693]: info: Initializing connection to go-librespot Websocket
Feb 12 23:23:06 volumio volumio[17693]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 23:23:06 volumio volumio[17693]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:23:06 volumio volumio[17693]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 12 23:23:06 volumio volumio[17693]:   errno: -111,
Feb 12 23:23:06 volumio volumio[17693]:   code: 'ECONNREFUSED',
Feb 12 23:23:06 volumio volumio[17693]:   syscall: 'connect',
Feb 12 23:23:06 volumio volumio[17693]:   address: '127.0.0.1',
Feb 12 23:23:06 volumio volumio[17693]:   port: 9879,
Feb 12 23:23:06 volumio volumio[17693]:   response: undefined
Feb 12 23:23:06 volumio volumio[17693]: }
Feb 12 23:23:06 volumio volumio[17693]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 23:23:07 volumio sudo[18082]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 23:22'
Feb 12 23:23:07 volumio sudo[18082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:08 volumio sudo[18082]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 12 23:23:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:08 volumio go-librespot[18089]: go-librespot daemon starting...
Feb 12 23:23:08 volumio go-librespot[18091]: time="2026-02-12T23:23:08+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:08 volumio go-librespot[18091]: time="2026-02-12T23:23:08+07:00" level=debug msg="app state loaded"
Feb 12 23:23:08 volumio go-librespot[18091]: time="2026-02-12T23:23:08+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:08 volumio go-librespot[18091]: time="2026-02-12T23:23: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 12 23:23:08 volumio go-librespot[18091]: time="2026-02-12T23:23: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 12 23:23:08 volumio go-librespot[18091]: time="2026-02-12T23:23: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 12 23:23:08 volumio go-librespot[18091]: time="2026-02-12T23:23:08+07:00" level=info msg="zeroconf server listening on port 34221"
Feb 12 23:23:09 volumio go-librespot[18091]: time="2026-02-12T23:23:09+07:00" level=debug msg="obtained new client token: AAAxWbnKwJBAW/QMiMejkT5T8+Oc8vsC0IqYxFdsT0aFkfV/5mo/t2QeY4uEP4YJnQpJISWpkaNhD0FK2QkN5oZaJb2O9RbcEnYnmuQu0M3sNKBnMjHFa+U0W90bnAzMO06LijzFqXdn+ngK1/8AkDdVRRvdLH/MYk7/dPFLN4XOUcJ4HHw3wMFrX/HjhOVZ8qeFXB7uShm89AW/JuiySynhAXp1oXG9vHjgEKF1mjrMamqOloTkWRs="
Feb 12 23:23:09 volumio go-librespot[18091]: time="2026-02-12T23:23:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:09 volumio go-librespot[18091]: time="2026-02-12T23:23:09+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 12 23:23:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:09 volumio volumio-remote-updater[643]: [2026-02-12 23:23:09] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Feb 12 23:23:09 volumio volumio-remote-updater[643]: [2026-02-12 23:23:09] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Feb 12 23:23:09 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:09 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 12 23:23:09 volumio systemd[1]: volumio.service: Consumed 54.662s CPU time.
Feb 12 23:23:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 23:23:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 23:23:09 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 13918.
Feb 12 23:23:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 23:23:09 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 12 23:23:09 volumio systemd[1]: volumio.service: Consumed 54.662s CPU time.
Feb 12 23:23:09 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 12 23:23:09 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 23:23:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 12 23:23:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:12 volumio go-librespot[18120]: go-librespot daemon starting...
Feb 12 23:23:12 volumio go-librespot[18121]: time="2026-02-12T23:23:12+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:12 volumio go-librespot[18121]: time="2026-02-12T23:23:12+07:00" level=debug msg="app state loaded"
Feb 12 23:23:12 volumio go-librespot[18121]: time="2026-02-12T23:23:12+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:13 volumio go-librespot[18121]: time="2026-02-12T23:23:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 12 23:23:13 volumio go-librespot[18121]: time="2026-02-12T23:23:13+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 12 23:23:13 volumio go-librespot[18121]: time="2026-02-12T23:23:13+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 12 23:23:13 volumio go-librespot[18121]: time="2026-02-12T23:23:13+07:00" level=info msg="zeroconf server listening on port 41643"
Feb 12 23:23:13 volumio go-librespot[18121]: time="2026-02-12T23:23:13+07:00" level=debug msg="obtained new client token: AAA6ZWNEIvoValycAreLs/Lj8CJjrb+6vxnMZDcvhbljGCHf/ri5ScOiz5u8+6cvOmklRyAVJ2LRming4NnnqFo/4VTFoTO+r87dnYv8McStjck2TEYnlfuuf6nk/uu742XWLAGus8JmRpqQUzyGil9uskZTr1yUKIcO/rDYT8ZBaGem3TLuPz61Tnp4inJOszPSZh7qwf1pHfkH6YFtIee09T+Ofyc85K8LfGFKjB1yPKvohleRtXFFKA=="
Feb 12 23:23:13 volumio volumio[18105]: info: -------------------------------------------
Feb 12 23:23:13 volumio volumio[18105]: info: -----            Volumio3              ----
Feb 12 23:23:13 volumio volumio[18105]: info: -------------------------------------------
Feb 12 23:23:13 volumio volumio[18105]: info: -----          System startup          ----
Feb 12 23:23:13 volumio volumio[18105]: info: -------------------------------------------
Feb 12 23:23:13 volumio go-librespot[18121]: time="2026-02-12T23:23:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:13 volumio go-librespot[18121]: time="2026-02-12T23:23:13+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 12 23:23:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:14 volumio volumio-remote-updater[643]: [2026-02-12 23:23:14] [connect] Successful connection
Feb 12 23:23:14 volumio volumio[18105]: info: MYVOLUMIO Environment detected
Feb 12 23:23:15 volumio volumio[18105]: info: Plugin folders cleanup
Feb 12 23:23:15 volumio volumio[18105]: info: Scanning into folder /volumio/app/plugins/
Feb 12 23:23:15 volumio volumio[18105]: info: Scanning category audio_interface
Feb 12 23:23:15 volumio volumio[18105]: info: Scanning category miscellanea
Feb 12 23:23:15 volumio volumio[18105]: info: Scanning category music_service
Feb 12 23:23:15 volumio volumio[18105]: info: Scanning category plugins.json
Feb 12 23:23:15 volumio volumio[18105]: info: Scanning category system_controller
Feb 12 23:23:15 volumio volumio[18105]: info: Scanning category user_interface
Feb 12 23:23:15 volumio volumio[18105]: info: Scanning into folder /data/plugins/
Feb 12 23:23:15 volumio volumio[18105]: info: Scanning category music_service
Feb 12 23:23:15 volumio volumio[18105]: info: Plugin folders cleanup completed
Feb 12 23:23:15 volumio volumio[18105]: info: -------------------------------------------
Feb 12 23:23:15 volumio volumio[18105]: info: -----      Core plugins startup        ----
Feb 12 23:23:15 volumio volumio[18105]: info: -------------------------------------------
Feb 12 23:23:15 volumio volumio[18105]: info: Loading plugins from folder /volumio/app/plugins/
Feb 12 23:23:15 volumio volumio[18105]: info: Adding plugin upnp to MyMusic Plugins
Feb 12 23:23:15 volumio volumio[18105]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 12 23:23:15 volumio volumio[18105]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 12 23:23:15 volumio volumio[18105]: info: Loading plugins from folder /data/plugins/
Feb 12 23:23:15 volumio volumio[18105]: info: Loading plugin "system"...
Feb 12 23:23:15 volumio volumio[18105]: info: Loading plugin "appearance"...
Feb 12 23:23:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 12 23:23:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:16 volumio go-librespot[18142]: go-librespot daemon starting...
Feb 12 23:23:16 volumio go-librespot[18143]: time="2026-02-12T23:23:16+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:16 volumio go-librespot[18143]: time="2026-02-12T23:23:16+07:00" level=debug msg="app state loaded"
Feb 12 23:23:16 volumio go-librespot[18143]: time="2026-02-12T23:23:16+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:17 volumio volumio[18105]: info: Loading plugin "network"...
Feb 12 23:23:17 volumio volumio[18105]: info: Refreshing Cached IP Addresses
Feb 12 23:23:17 volumio sudo[18150]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 23:23:17 volumio sudo[18150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:17 volumio sudo[18150]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:17 volumio sudo[18152]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 23:23:17 volumio sudo[18152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:17 volumio volumio[18105]: info: Loading plugin "services"...
Feb 12 23:23:17 volumio sudo[18152]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:17 volumio volumio[18105]: info: Loading plugin "alsa_controller"...
Feb 12 23:23:17 volumio sudo[18161]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 12 23:23:17 volumio sudo[18161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:17 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 23:23:17 volumio volumio[18105]: info: Loading plugin "wizard"...
Feb 12 23:23:17 volumio volumio[18105]: info: Loading plugin "networkfs"...
Feb 12 23:23:17 volumio volumio[18105]: info: Starting Udev Watcher for removable devices
Feb 12 23:23:17 volumio volumio[18105]: info: Ignoring mount for partition: boot
Feb 12 23:23:17 volumio volumio[18105]: info: Ignoring mount for partition: volumio
Feb 12 23:23:17 volumio volumio[18105]: info: Ignoring mount for partition: volumio_data
Feb 12 23:23:17 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 23:23:17 volumio volumio[18105]: info: Loading plugin "volumio_command_line_client"...
Feb 12 23:23:17 volumio volumio[18105]: info: Loading plugin "upnp"...
Feb 12 23:23:17 volumio volumio[18105]: info: [1770913397501] Starting Upmpd Daemon
Feb 12 23:23:17 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 23:23:17 volumio volumio[18105]: info: Loading plugin "my_music"...
Feb 12 23:23:17 volumio volumio[18105]: info: Loading plugin "mpd"...
Feb 12 23:23:17 volumio go-librespot[18143]: time="2026-02-12T23:23:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 12 23:23:17 volumio go-librespot[18143]: time="2026-02-12T23:23:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 12 23:23:17 volumio go-librespot[18143]: time="2026-02-12T23:23:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 12 23:23:17 volumio go-librespot[18143]: time="2026-02-12T23:23:17+07:00" level=info msg="zeroconf server listening on port 33027"
Feb 12 23:23:17 volumio go-librespot[18143]: time="2026-02-12T23:23:17+07:00" level=debug msg="obtained new client token: AADurIBiNjjBIjc/CqLbnlyR5b013MI0xrrS8AScOJrVu1NpoLdMsDBL4eWIV56EkwnvdxVLa83e7J+xjbSYwKBdBujHZDJ655BkizgzBlPRdquHQ4HwFFMgL1UprSAXkkqZgM1OGBwkzaCfLx4uulTU9JzawTtsA1O0wv9TbexfMDo4HKFFwyowfCHk1CKJkrcytjBVaBlQyN22QZZOKpn0CXM0Uf3hJLK/gZS8yN88sXNZ5IJnLbpLHQ=="
Feb 12 23:23:17 volumio go-librespot[18143]: time="2026-02-12T23:23:17+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 12 23:23:18 volumio go-librespot[18143]: time="2026-02-12T23:23:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 12 23:23:18 volumio go-librespot[18143]: time="2026-02-12T23:23:18+07:00" level=debug msg="completed keyexchange"
Feb 12 23:23:18 volumio go-librespot[18143]: time="2026-02-12T23:23:18+07:00" level=debug msg="completed challenge"
Feb 12 23:23:18 volumio volumio[18105]: info: Loading plugin "upnp_browser"...
Feb 12 23:23:18 volumio go-librespot[18143]: time="2026-02-12T23:23: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 12 23:23:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:19 volumio sudo[18161]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:21 volumio volumio[18105]: info: Starting UPNP Browser
Feb 12 23:23:21 volumio volumio[18105]: info: Loading plugin "alarm-clock"...
Feb 12 23:23:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 12 23:23:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:21 volumio go-librespot[18185]: go-librespot daemon starting...
Feb 12 23:23:21 volumio volumio[18105]: info: Loading plugin "airplay_emulation"...
Feb 12 23:23:21 volumio volumio[18105]: info: Starting Shairport Sync
Feb 12 23:23:21 volumio volumio[18105]: info: Loading plugin "last_100"...
Feb 12 23:23:21 volumio go-librespot[18186]: time="2026-02-12T23:23:21+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:21 volumio go-librespot[18186]: time="2026-02-12T23:23:21+07:00" level=debug msg="app state loaded"
Feb 12 23:23:21 volumio volumio[18105]: info: Loading plugin "webradio"...
Feb 12 23:23:21 volumio go-librespot[18186]: time="2026-02-12T23:23:21+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:21 volumio volumio[18105]: info: Loading plugin "i2s_dacs"...
Feb 12 23:23:21 volumio volumio[18105]: info: Loading plugin "volumiodiscovery"...
Feb 12 23:23:21 volumio volumio[18105]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 23:23:21 volumio volumio[18105]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 23:23:21 volumio volumio[18105]: *** WARNING *** For more information see 
Feb 12 23:23:21 volumio volumio[18105]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 23:23:21 volumio volumio[18105]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 23:23:21 volumio volumio[18105]: *** WARNING *** For more information see 
Feb 12 23:23:21 volumio node[18105]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 23:23:21 volumio node[18105]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 23:23:21 volumio node[18105]: *** WARNING *** For more information see 
Feb 12 23:23:21 volumio node[18105]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 23:23:21 volumio node[18105]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 23:23:21 volumio node[18105]: *** WARNING *** For more information see 
Feb 12 23:23:21 volumio volumio[18105]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 12 23:23:21 volumio volumio[18105]: info: Discovery: Started advertising with name: Volumio
Feb 12 23:23:21 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 23:23:21 volumio volumio[18105]: info: Loading plugin "spop"...
Feb 12 23:23:21 volumio go-librespot[18186]: time="2026-02-12T23:23:21+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 12 23:23:22 volumio go-librespot[18186]: time="2026-02-12T23:23:22+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 12 23:23:22 volumio go-librespot[18186]: time="2026-02-12T23:23:22+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 12 23:23:22 volumio go-librespot[18186]: time="2026-02-12T23:23:22+07:00" level=info msg="zeroconf server listening on port 43483"
Feb 12 23:23:22 volumio go-librespot[18186]: time="2026-02-12T23:23:22+07:00" level=debug msg="obtained new client token: AACpFVnoaReCXERUZQT0pcewNcj2yr3AMx99KXK/5i3mYJGBSE08kjgJNBItmu85sW6bMueLJkx0gtRXSyIVXeSGlPhU0vpARS26ZNtYLvJNbHNKKN87T6EUWI9EpexQ7KD12so+hpS1GYa5bdTO5vx/m8jAfzleEswXpAMeqnGlPRcSV0Q7s8I1EYDvDGa6VamXKzw0AAQOm55NWPg+meE6C+YgZqpWzovACoTuvOqMLbQbPgOm6Ts="
Feb 12 23:23:22 volumio go-librespot[18186]: time="2026-02-12T23:23:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:22 volumio go-librespot[18186]: time="2026-02-12T23:23:22+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 12 23:23:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:23 volumio volumio[18105]: info: Loading plugin "ytcr"...
Feb 12 23:23:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 12 23:23:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:25 volumio go-librespot[18195]: go-librespot daemon starting...
Feb 12 23:23:25 volumio go-librespot[18196]: time="2026-02-12T23:23:25+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:25 volumio go-librespot[18196]: time="2026-02-12T23:23:25+07:00" level=debug msg="app state loaded"
Feb 12 23:23:25 volumio go-librespot[18196]: time="2026-02-12T23:23:25+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:26 volumio go-librespot[18196]: time="2026-02-12T23:23:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 23:23:26 volumio go-librespot[18196]: time="2026-02-12T23:23:26+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 12 23:23:26 volumio go-librespot[18196]: time="2026-02-12T23:23:26+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 12 23:23:26 volumio go-librespot[18196]: time="2026-02-12T23:23:26+07:00" level=info msg="zeroconf server listening on port 45687"
Feb 12 23:23:26 volumio volumio[18105]: info: Loading plugin "ytmusic"...
Feb 12 23:23:26 volumio go-librespot[18196]: time="2026-02-12T23:23:26+07:00" level=debug msg="obtained new client token: AADTp8E8RBrPtl5AHU1zS+JknrgtsbQnTRrZ6IWW66o1U7ZpFi1In8SQ+kVskEU5IbzR6+seYtGHURrvoThm9D7OG0z/CRDfIwpF/b56dTaoRwbxa5RYavd+nV7JbT3f/Ak28FHEYoetmRh+b7dbizKG1C+1iCwQA4wiM4W0XgkSMUhKwTser59JAXkJI5aQVG0eYrx27zCWJbIBCi1fw9CotTcoQamtYKJFHz+/u5u2V9qMbEG5SrRuGg=="
Feb 12 23:23:26 volumio go-librespot[18196]: time="2026-02-12T23:23:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:26 volumio go-librespot[18196]: time="2026-02-12T23:23:26+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 12 23:23:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:27 volumio volumio-remote-updater[643]: [2026-02-12 23:23:27] [connect] Successful connection
Feb 12 23:23:27 volumio volumio[18105]: info: Loading plugin "outputs"...
Feb 12 23:23:27 volumio volumio[18105]: info: Loading plugin "albumart"...
Feb 12 23:23:27 volumio volumio[18105]: info: Plugin example_plugin is not enabled
Feb 12 23:23:27 volumio volumio[18105]: info: Loading plugin "inputs"...
Feb 12 23:23:27 volumio volumio[18105]: info: Loading plugin "updater_comm"...
Feb 12 23:23:27 volumio volumio[18105]: info: Plugin mpdemulation is not enabled
Feb 12 23:23:27 volumio volumio[18105]: info: Loading plugin "rest_api"...
Feb 12 23:23:27 volumio volumio[18105]: info: Loading plugin "websocket"...
Feb 12 23:23:27 volumio volumio[18105]: info: Starting Socket.io Server version 1.7.4
Feb 12 23:23:27 volumio volumio[18105]: info: Loading plugin "RoonBridge"...
Feb 12 23:23:28 volumio volumio[18105]: info: Applying required configuration parameters for plugin RoonBridge
Feb 12 23:23:28 volumio volumio[18105]: info: Loading i18n strings for locale en
Feb 12 23:23:28 volumio volumio[18105]: Updating browse sources language
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::initPlayerControls
Feb 12 23:23:28 volumio volumio[18217]: Forking 3 albumart workers
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 23:23:28 volumio volumio[18105]: Express server listening on port 3000
Feb 12 23:23:28 volumio volumio[18105]:  [Metrics]  WebUI:  16s 49.81ms 
Feb 12 23:23:28 volumio volumio[18105]: info: CoreStateMachine::resetVolumioState
Feb 12 23:23:28 volumio volumio[18105]: info: CoreStateMachine::getcurrentVolume
Feb 12 23:23:28 volumio volumio[18105]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 23:23:28 volumio volumio[18105]: info: Volumio Network Manager: Network status updated: 1
Feb 12 23:23:28 volumio sudo[18259]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 23:23:28 volumio sudo[18259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:28 volumio sudo[18261]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 23:23:28 volumio sudo[18261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:28 volumio sudo[18259]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:28 volumio sudo[18261]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:29 volumio volumio[18105]: info: VolumeController:: Volume=100 Mute =false
Feb 12 23:23:29 volumio volumio[18105]: info: CoreStateMachine::pushState
Feb 12 23:23:29 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::volumioPushState
Feb 12 23:23:29 volumio volumio[18105]: info: CoreStateMachine::updateTrackBlock
Feb 12 23:23:29 volumio volumio[18105]: info: CorePlayQueue::getTrackBlock
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 23:23:29 volumio volumio-remote-updater[643]: [2026-02-12 23:23:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770913407 101
Feb 12 23:23:29 volumio volumio[18105]: 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 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:29 volumio volumio[18105]: info: Reloading queue from file
Feb 12 23:23:29 volumio volumio[18105]: info: CoreStateMachine::setRepeat null single undefined
Feb 12 23:23:29 volumio volumio[18105]: info: CoreStateMachine::pushState
Feb 12 23:23:29 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::volumioPushState
Feb 12 23:23:29 volumio volumio[18105]: info: CoreStateMachine::setRandom null
Feb 12 23:23:29 volumio volumio[18105]: info: CoreStateMachine::pushState
Feb 12 23:23:29 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::volumioPushState
Feb 12 23:23:29 volumio volumio[18105]: info: Setting Device type: Raspberry PI
Feb 12 23:23:29 volumio volumio[18105]: info: Completed loading Core Plugins
Feb 12 23:23:29 volumio volumio[18105]: info: Preparing to generate the ALSA configuration file
Feb 12 23:23:29 volumio volumio[18105]: info: VolumeController:: Volume=100 Mute =false
Feb 12 23:23:29 volumio volumio[18105]: info: CoreStateMachine::pushState
Feb 12 23:23:29 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::volumioPushState
Feb 12 23:23:29 volumio volumio[18105]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 23:23:29 volumio volumio[18105]: info: Output device has changed, restarting MPD
Feb 12 23:23:29 volumio volumio[18105]: info: Output device has changed, restarting Shairport Sync
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:29 volumio sudo[18277]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 12 23:23:29 volumio sudo[18277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:29 volumio sudo[18279]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 23:23:29 volumio volumio[18105]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 23:23:29 volumio sudo[18279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:29 volumio volumio[18105]: info: ___________ START PLUGINS ___________
Feb 12 23:23:29 volumio sudo[18281]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 23:23:29 volumio sudo[18281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:29 volumio sudo[18279]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:29 volumio volumio[18105]: info: ControllerMpd::onStart: Initializing MPD
Feb 12 23:23:29 volumio volumio[18105]: info: Creating MPD Configuration file
Feb 12 23:23:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 12 23:23:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 23:23:29 volumio volumio[18105]: info: [1770913409904] CoreMusicLibrary::Adding element Media Servers
Feb 12 23:23:29 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:23:29 volumio sudo[18290]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 23:23:29 volumio sudo[18290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:29 volumio volumio[18105]: info: UPNP Browser: Client initialized successfully
Feb 12 23:23:29 volumio sudo[18290]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:30 volumio sudo[18293]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 23:23:30 volumio sudo[18293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:30 volumio go-librespot[18291]: go-librespot daemon starting...
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:30 volumio sudo[18277]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:30 volumio go-librespot[18296]: time="2026-02-12T23:23:30+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:30 volumio go-librespot[18296]: time="2026-02-12T23:23:30+07:00" level=debug msg="app state loaded"
Feb 12 23:23:30 volumio go-librespot[18296]: time="2026-02-12T23:23:30+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 12 23:23:30 volumio volumio[18105]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:30 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 23:23:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 23:23:30 volumio systemd[1]: mpd.service: Consumed 7.224s CPU time.
Feb 12 23:23:30 volumio volumio[18105]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 23:23:30 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 23:23:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 23:23:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 23:23:30 volumio volumio[18105]: info: [1770913410288] CoreMusicLibrary::Adding element Last_100
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 23:23:30 volumio volumio[18105]: info: [1770913410303] CoreMusicLibrary::Adding element Webradio
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 23:23:30 volumio volumio[18105]: info: Initializing BBC Radios
Feb 12 23:23:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 23:23:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:30 volumio volumio[18105]: info: Creating Spotify config file
Feb 12 23:23:30 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:30 volumio go-librespot[18296]: time="2026-02-12T23:23:30+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 12 23:23:30 volumio go-librespot[18296]: time="2026-02-12T23:23:30+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 12 23:23:30 volumio go-librespot[18296]: time="2026-02-12T23:23:30+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 12 23:23:30 volumio go-librespot[18296]: time="2026-02-12T23:23:30+07:00" level=info msg="zeroconf server listening on port 38025"
Feb 12 23:23:30 volumio sudo[18314]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 23:23:30 volumio sudo[18314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 23:23:30 volumio sudo[18314]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:31 volumio go-librespot[18296]: time="2026-02-12T23:23:31+07:00" level=debug msg="obtained new client token: AAAR4UQa98Iq5IybeGxUbd1Uk5dLOSW6QuiUBaY9MHPfhtFtSno7rfSTb+wLusoHX8f62tgJen3M0efEAw++B5CI/tBl+bVWZqDLHylqS5eBW5gCLH0tegNCSbAOw917GEnkVjbcJBAasE2iDoTu7NalgaqJ5KbuM2+U5GUGuFEwqRuALoUlwxkPEzfkdFUX5Pe0we/Zb4YnORUM6FthYm6b80sfsIPBqkLFjfKk6Vi6Yt0rzLnbCkw="
Feb 12 23:23:31 volumio go-librespot[18296]: time="2026-02-12T23:23:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:31 volumio go-librespot[18296]: time="2026-02-12T23:23:31+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 12 23:23:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:31 volumio volumio[18228]: Starting albumart workers
Feb 12 23:23:31 volumio volumio[18105]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 23:23:31 volumio volumio[18105]: info: [1770913411810] CoreMusicLibrary::Adding element YouTube Music
Feb 12 23:23:31 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:23:31 volumio volumio[18105]: Cannot find translation for source YouTube Music
Feb 12 23:23:31 volumio volumio[18105]: info: Volumio Calling Home
Feb 12 23:23:31 volumio sudo[18331]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 12 23:23:31 volumio sudo[18331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:32 volumio sudo[18331]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:32 volumio volumio[18227]: Starting albumart workers
Feb 12 23:23:32 volumio volumio[18229]: Starting albumart workers
Feb 12 23:23:32 volumio volumio[18105]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 12 23:23:32 volumio volumio[18105]: info: Discovery: Found device Volumio
Feb 12 23:23:32 volumio volumio[18105]: info: CoreCommandRouter::volumioGetState
Feb 12 23:23:32 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:32 volumio volumio[18105]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 12 23:23:32 volumio volumio[18105]: info: Discovery: Found device Volumio
Feb 12 23:23:32 volumio volumio[18105]: info: CoreCommandRouter::volumioGetState
Feb 12 23:23:32 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:32 volumio volumio[18105]: info: MPD Permissions set
Feb 12 23:23:32 volumio volumio[18105]: info: MPD Permissions set
Feb 12 23:23:32 volumio volumio[18105]: info: Upmpdcli Daemon Started
Feb 12 23:23:32 volumio volumio[18105]: info: Spotify config file written
Feb 12 23:23:32 volumio sudo[18338]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 12 23:23:32 volumio sudo[18338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:32 volumio volumio[18105]: 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 12 23:23:33 volumio volumio[18105]: info: Volumio called home
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:33 volumio go-librespot[18345]: go-librespot daemon starting...
Feb 12 23:23:33 volumio sudo[18338]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:23:33 volumio volumio[18105]: info: No need to fix Spotify hosts
Feb 12 23:23:33 volumio go-librespot[18350]: time="2026-02-12T23:23:33+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:33 volumio go-librespot[18350]: time="2026-02-12T23:23:33+07:00" level=debug msg="app state loaded"
Feb 12 23:23:33 volumio go-librespot[18350]: time="2026-02-12T23:23:33+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:33 volumio go-librespot[18350]: time="2026-02-12T23:23:33+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 12 23:23:33 volumio go-librespot[18350]: time="2026-02-12T23:23:33+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 12 23:23:33 volumio go-librespot[18350]: time="2026-02-12T23:23:33+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 12 23:23:34 volumio go-librespot[18350]: time="2026-02-12T23:23:34+07:00" level=info msg="zeroconf server listening on port 41869"
Feb 12 23:23:34 volumio go-librespot[18350]: time="2026-02-12T23:23:34+07:00" level=debug msg="obtained new client token: AADFkfEJYA1B8rDaWqv7ZBWkd0jHf4qSHfPq9aS5l1Ni/3IEK+R+qd6uVlfiUr7iWWz9dK5z2WW8Wd4/93RdDFPgRpHTrtBUlXSyXT8O5v+KDPP3kgPQk52wTTgWg5Nh/AeFpgkdtMmQn2KLowCrc/TNf5VaGE4OXYWlzT840uwUfygKK3OiEEdypAu2ZFh8ic/iPQpooxRzgVG2uqHCI+hEzBnwF/zqX/9l3iaBV/tdgjKSuI5zpPowdg=="
Feb 12 23:23:34 volumio go-librespot[18350]: time="2026-02-12T23:23:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:34 volumio go-librespot[18350]: time="2026-02-12T23:23:34+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 12 23:23:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:34 volumio volumio[18105]: info: Starting Shairport Sync
Feb 12 23:23:34 volumio volumio[18105]: info: Starting Shairport Sync
Feb 12 23:23:34 volumio volumio[18105]: info: Starting Shairport Sync
Feb 12 23:23:34 volumio sudo[18377]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 23:23:34 volumio sudo[18377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:34 volumio sudo[18381]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 23:23:34 volumio sudo[18381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:34 volumio sudo[18379]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 23:23:34 volumio sudo[18379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:35 volumio volumio[18105]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 23:23:35 volumio volumio[18105]: SPOTIFY: BQCQpQsLAvFkPgQOxlIVeMN6JI0w1clZWgHf_EFowacUA22kZycmTOvJRKGhyZCXEq8Px5WHkVHV5--jyFnVXnBcOOpwfdjSFmIgf_T2f3F9kOSk3fwsqs91L5Kpz4DqDsjRkf9F4WPu5NLDRoHAN_WsuyTDTNx9Gmq0RB6OzON-Ew6KrUqj5tiI8J-IqNZBpfdAjGebjb4q2IRKXr_HWm362mfaYMf-_CEmrjGYNd2DRVggcApBBT6sdrQ8RLUlyNaYNjsxW7sPo-CTv1ZlKHUIQxx498mAYKnCGobzoISwa3LAd-ApiaLZ
Feb 12 23:23:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 23:23:35 volumio volumio[18105]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 23:23:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 23:23:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 23:23:35 volumio systemd[1]: shairport-sync.service: Consumed 2.321s CPU time.
Feb 12 23:23:35 volumio volumio[18105]: info: New Spotify access token = BQCQpQsLAvFkPgQOxlIVeMN6JI0w1clZWgHf_EFowacUA22kZycmTOvJRKGhyZCXEq8Px5WHkVHV5--jyFnVXnBcOOpwfdjSFmIgf_T2f3F9kOSk3fwsqs91L5Kpz4DqDsjRkf9F4WPu5NLDRoHAN_WsuyTDTNx9Gmq0RB6OzON-Ew6KrUqj5tiI8J-IqNZBpfdAjGebjb4q2IRKXr_HWm362mfaYMf-_CEmrjGYNd2DRVggcApBBT6sdrQ8RLUlyNaYNjsxW7sPo-CTv1ZlKHUIQxx498mAYKnCGobzoISwa3LAd-ApiaLZ
Feb 12 23:23:35 volumio volumio[18105]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 12 23:23:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 23:23:35 volumio volumio[18105]: info: CoreCommandRouter::volumioGetState
Feb 12 23:23:35 volumio sudo[18377]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:35 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:35 volumio sudo[18381]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:35 volumio sudo[18379]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:35 volumio volumio[18105]: info: Shairport-Sync Started
Feb 12 23:23:35 volumio volumio[18105]: Error adding Membership: Error: addMembership EINVAL
Feb 12 23:23:35 volumio volumio[18105]: info: Shairport-Sync Started
Feb 12 23:23:35 volumio volumio[18105]: info: Shairport-Sync Started
Feb 12 23:23:35 volumio volumio[18105]: 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 12 23:23:35 volumio volumio[18105]: info: Spotify Successfully logged in
Feb 12 23:23:35 volumio volumio[18105]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 23:23:35 volumio volumio[18105]: info: [1770913415569] CoreMusicLibrary::Adding element Spotify
Feb 12 23:23:35 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:23:35 volumio volumio[18105]: Cannot find translation for source YouTube Music
Feb 12 23:23:35 volumio volumio[18105]: Cannot find translation for source Spotify
Feb 12 23:23:36 volumio volumio[18105]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 12 23:23:36 volumio volumio[18105]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 23:23:36 volumio volumio[18105]: info: VolumeController:: Volume=100 Mute =false
Feb 12 23:23:36 volumio volumio[18105]: info: CoreCommandRouter::volumioGetState
Feb 12 23:23:36 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:36 volumio volumio[18105]: info: CoreStateMachine::pushState
Feb 12 23:23:36 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:36 volumio volumio[18105]: info: CoreCommandRouter::volumioPushState
Feb 12 23:23:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Feb 12 23:23:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:37 volumio go-librespot[18417]: go-librespot daemon starting...
Feb 12 23:23:37 volumio go-librespot[18418]: time="2026-02-12T23:23:37+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:37 volumio go-librespot[18418]: time="2026-02-12T23:23:37+07:00" level=debug msg="app state loaded"
Feb 12 23:23:37 volumio go-librespot[18418]: time="2026-02-12T23:23:37+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:37 volumio volumio[18105]: info: go-librespot daemon successfully initialized
Feb 12 23:23:37 volumio mpd[18328]: 2026-02-12T23:23:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 12 23:23:37 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 12 23:23:37 volumio sudo[18281]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:37 volumio sudo[18293]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:38 volumio volumio[18105]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 23:23:38 volumio volumio[18105]:   assert.ok(self.idling)
Feb 12 23:23:38 volumio volumio[18105]: error: The expression evaluated to a falsy value:
Feb 12 23:23:38 volumio volumio[18105]:   assert.ok(self.idling)
Feb 12 23:23:38 volumio volumio[18105]: info: MPD running with PID18328
Feb 12 23:23:38 volumio volumio[18105]:  ,establishing connection
Feb 12 23:23:38 volumio volumio[18105]: error: updateQueue error: null
Feb 12 23:23:38 volumio volumio[18105]: info: Completed starting Core Plugins
Feb 12 23:23:38 volumio volumio[18105]: info: -------------------------------------------
Feb 12 23:23:38 volumio volumio[18105]: info: -----    MyVolumio plugins startup     ----
Feb 12 23:23:38 volumio volumio[18105]: info: -------------------------------------------
Feb 12 23:23:38 volumio volumio[18105]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 12 23:23:38 volumio go-librespot[18418]: time="2026-02-12T23:23:38+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 12 23:23:38 volumio go-librespot[18418]: time="2026-02-12T23:23:38+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 12 23:23:38 volumio go-librespot[18418]: time="2026-02-12T23:23:38+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 12 23:23:38 volumio volumio[18105]: error: updateQueue error: null
Feb 12 23:23:38 volumio go-librespot[18418]: time="2026-02-12T23:23:38+07:00" level=info msg="zeroconf server listening on port 39073"
Feb 12 23:23:38 volumio go-librespot[18418]: time="2026-02-12T23:23:38+07:00" level=debug msg="obtained new client token: AADRKJFd6ynY+HezavcVgYiQc5i6VKckgGVMlawbKshmfwsRrh2xrYsy9nsacean96p1JJE/sFwoNPDMPLWE2uTuhOYIu65Bh1/U5CX5dQPcSjRgp5kkHGWWoqTqdLTBo5y0QEgXaEsTCvDyGU5ufLcITw1lH1Go7qSQOB5JAzcWOam6aM7K3Jn3jxEM40kz8D0oOsnMusU2/0estrSixlRLFx+v71YfgkmoZt7NxLlw9kD327cGUyeTvw=="
Feb 12 23:23:38 volumio go-librespot[18418]: time="2026-02-12T23:23:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:38 volumio go-librespot[18418]: time="2026-02-12T23:23:38+07:00" level=debug msg="completed keyexchange"
Feb 12 23:23:38 volumio go-librespot[18418]: time="2026-02-12T23:23:38+07:00" level=debug msg="completed challenge"
Feb 12 23:23:38 volumio go-librespot[18418]: time="2026-02-12T23:23:38+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 12 23:23:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:40 volumio volumio[18105]: info: Initializing connection to go-librespot Websocket
Feb 12 23:23:40 volumio volumio[18105]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:23:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Feb 12 23:23:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:41 volumio go-librespot[18429]: go-librespot daemon starting...
Feb 12 23:23:41 volumio go-librespot[18430]: time="2026-02-12T23:23:41+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:41 volumio go-librespot[18430]: time="2026-02-12T23:23:41+07:00" level=debug msg="app state loaded"
Feb 12 23:23:41 volumio go-librespot[18430]: time="2026-02-12T23:23:41+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:42 volumio go-librespot[18430]: time="2026-02-12T23:23:42+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 12 23:23:42 volumio go-librespot[18430]: time="2026-02-12T23:23:42+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 12 23:23:42 volumio go-librespot[18430]: time="2026-02-12T23:23:42+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 12 23:23:42 volumio go-librespot[18430]: time="2026-02-12T23:23:42+07:00" level=info msg="zeroconf server listening on port 37705"
Feb 12 23:23:42 volumio go-librespot[18430]: time="2026-02-12T23:23:42+07:00" level=debug msg="obtained new client token: AAAVXIZY6Wgu1xs6zqRePTgUBgOf45w/YJZ0EqiacyffjyzOHgOiJKkU+jSDvOgJRjlOD13+2JR0IS3OHArg+HnTzeOUOFztCZ811dn/bXaD2UzFEDnjllYtKr2E8Ebxm2+NqQo72OxV7QYxYzmXRMQE6b9pK58u6Rs3u7xJ04FxVEMVU3fCrXUaWV2uhwEvItbA6v+T/ENVlm8X9y/c971HyWc0xj5DiIU+cqJCRuQ0/rBbSuVMNcIb2A=="
Feb 12 23:23:42 volumio go-librespot[18430]: time="2026-02-12T23:23:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:42 volumio go-librespot[18430]: time="2026-02-12T23:23:42+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 12 23:23:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:42 volumio volumio[18105]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 12 23:23:43 volumio volumio[18105]: info: Initializing connection to go-librespot Websocket
Feb 12 23:23:43 volumio volumio[18105]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:23:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Feb 12 23:23:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:46 volumio go-librespot[18438]: go-librespot daemon starting...
Feb 12 23:23:46 volumio go-librespot[18439]: time="2026-02-12T23:23:46+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:46 volumio go-librespot[18439]: time="2026-02-12T23:23:46+07:00" level=debug msg="app state loaded"
Feb 12 23:23:46 volumio go-librespot[18439]: time="2026-02-12T23:23:46+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:46 volumio go-librespot[18439]: time="2026-02-12T23:23:46+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 12 23:23:46 volumio go-librespot[18439]: time="2026-02-12T23:23:46+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 12 23:23:46 volumio go-librespot[18439]: time="2026-02-12T23:23:46+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 12 23:23:46 volumio go-librespot[18439]: time="2026-02-12T23:23:46+07:00" level=info msg="zeroconf server listening on port 36489"
Feb 12 23:23:46 volumio volumio[18105]: info: Initializing connection to go-librespot Websocket
Feb 12 23:23:46 volumio go-librespot[18439]: time="2026-02-12T23:23:46+07:00" level=debug msg="new websocket client"
Feb 12 23:23:46 volumio volumio[18105]: info: Connection to go-librespot Websocket established
Feb 12 23:23:46 volumio go-librespot[18439]: time="2026-02-12T23:23:46+07:00" level=debug msg="obtained new client token: AADCL49lqUjFGcpYCP3NrlBdgJ/55Huvmy4LYHYQ4s7jwCLix9lqNZEhiPHxAwtVDegvt3nSBriF8RjjFHzr2TB3OkOIeYx8paM5grT91ub1cH4eXy8b9YGDI9/AS9wWw+8Ud9EhAcZL30+z7/f6vQDe9Cl3FcskAAm136PcDOyglu3WOIihVdozClsVu7oEizPJ3qHiqxUozskspDsYXjcEZs4ESw2pmt8FSd2fVbAGgnbk7ZC8+PSq+g=="
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 12 23:23:47 volumio volumio[18105]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 12 23:23:47 volumio volumio[18105]: info: Adding plugin multiroom to MyMusic Plugins
Feb 12 23:23:47 volumio go-librespot[18439]: time="2026-02-12T23:23:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:47 volumio volumio[18105]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 12 23:23:47 volumio volumio[18105]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 12 23:23:47 volumio volumio[18105]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 12 23:23:47 volumio volumio[18105]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 12 23:23:47 volumio volumio[18105]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 12 23:23:47 volumio volumio[18105]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 12 23:23:47 volumio go-librespot[18439]: time="2026-02-12T23:23:47+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 12 23:23:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:48 volumio volumio[18105]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 12 23:23:48 volumio volumio[18105]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 12 23:23:48 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:48 volumio volumio[18105]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:23:48 volumio volumio[18105]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 12 23:23:48 volumio volumio[18105]: info: MyVolumio login type: Token
Feb 12 23:23:49 volumio volumio[18105]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 12 23:23:49 volumio volumio[18105]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 12 23:23:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Feb 12 23:23:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:50 volumio go-librespot[18461]: go-librespot daemon starting...
Feb 12 23:23:50 volumio go-librespot[18462]: time="2026-02-12T23:23:50+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:50 volumio go-librespot[18462]: time="2026-02-12T23:23:50+07:00" level=debug msg="app state loaded"
Feb 12 23:23:50 volumio go-librespot[18462]: time="2026-02-12T23:23:50+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:50 volumio volumio[18105]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 12 23:23:50 volumio volumio[18105]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 12 23:23:50 volumio volumio[18105]: info: Streaming services startup
Feb 12 23:23:50 volumio volumio[18105]: info: Starting Streaming Daemon
Feb 12 23:23:50 volumio sudo[18471]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 23:23:50 volumio sudo[18471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:50 volumio volumio[18105]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 12 23:23:50 volumio sudo[18471]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:51 volumio volumio[18105]: info: Getting Spotify volume
Feb 12 23:23:51 volumio go-librespot[18462]: time="2026-02-12T23:23:51+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 12 23:23:51 volumio go-librespot[18462]: time="2026-02-12T23:23:51+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 12 23:23:51 volumio go-librespot[18462]: time="2026-02-12T23:23:51+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 12 23:23:51 volumio volumio[18105]: info: Connection to go-librespot Websocket closed
Feb 12 23:23:51 volumio volumio[18105]: error: Cannot start Volumio Streaming Daemon
Feb 12 23:23:51 volumio volumio[18105]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 12 23:23:51 volumio volumio[18105]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 12 23:23:51 volumio go-librespot[18462]: time="2026-02-12T23:23:51+07:00" level=info msg="zeroconf server listening on port 37509"
Feb 12 23:23:51 volumio volumio[18105]: 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 12 23:23:51 volumio go-librespot[18462]: time="2026-02-12T23:23:51+07:00" level=debug msg="obtained new client token: AACrYl3Leh79f91w3spFz5OGEky8Odyp5YaSIGz8ItyoIZFiSynrknXeIEiJSo5c22/nC2k/akZHObwmSCdzISjKPkgPktsoxQkygRM8uKLOB5I0qX+szl3CC4aNjcRj7d3VbV1QmCmrV/HqYNiwBD7nERD9pxxTp9ao46jMQ9pCrTs+iC6Dosxnw9/BK4BOXdpXvdpj7s1hLht9u/qdablcYT3XljtcyXPVhPMwBiQ5HISuGkmtFXY="
Feb 12 23:23:51 volumio volumio[18105]: info: CoreCommandRouter::volumioGetState
Feb 12 23:23:51 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:51 volumio volumio[18105]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 12 23:23:51 volumio volumio[18105]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 12 23:23:51 volumio volumio[18105]: SPOTIFY: VOLUMIO VOLUME 100
Feb 12 23:23:51 volumio volumio[18105]: info: Aligning Spotify Volume to Volumio Volume
Feb 12 23:23:51 volumio volumio[18105]: info: CoreCommandRouter::volumioGetState
Feb 12 23:23:51 volumio volumio[18105]: info: CorePlayQueue::getTrack 0
Feb 12 23:23:51 volumio volumio[18105]: info: Setting Spotify Volume from Volumio: 100
Feb 12 23:23:51 volumio go-librespot[18462]: time="2026-02-12T23:23:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:51 volumio go-librespot[18462]: time="2026-02-12T23:23:51+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 12 23:23:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:51 volumio volumio[18105]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 23:23:51 volumio volumio[18105]: Error: socket hang up
Feb 12 23:23:51 volumio volumio[18105]:     at connResetException (node:internal/errors:720:14)
Feb 12 23:23:51 volumio volumio[18105]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 12 23:23:51 volumio volumio[18105]:     at Socket.emit (node:events:526:35)
Feb 12 23:23:51 volumio volumio[18105]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 12 23:23:51 volumio volumio[18105]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 12 23:23:51 volumio volumio[18105]:   code: 'ECONNRESET',
Feb 12 23:23:51 volumio volumio[18105]:   response: undefined
Feb 12 23:23:51 volumio volumio[18105]: }
Feb 12 23:23:51 volumio volumio[18105]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 23:23:52 volumio sudo[18491]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 23:22'
Feb 12 23:23:52 volumio sudo[18491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:23:53 volumio sudo[18491]: pam_unix(sudo:session): session closed for user root
Feb 12 23:23:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Feb 12 23:23:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:54 volumio go-librespot[18499]: go-librespot daemon starting...
Feb 12 23:23:54 volumio go-librespot[18500]: time="2026-02-12T23:23:54+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:54 volumio go-librespot[18500]: time="2026-02-12T23:23:54+07:00" level=debug msg="app state loaded"
Feb 12 23:23:54 volumio go-librespot[18500]: time="2026-02-12T23:23:54+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:54 volumio volumio-remote-updater[643]: [2026-02-12 23:23:54] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Feb 12 23:23:54 volumio volumio-remote-updater[643]: [2026-02-12 23:23:54] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Feb 12 23:23:54 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:54 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 12 23:23:54 volumio systemd[1]: volumio.service: Consumed 55.555s CPU time.
Feb 12 23:23:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 23:23:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 23:23:54 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 13919.
Feb 12 23:23:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 23:23:54 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 12 23:23:54 volumio systemd[1]: volumio.service: Consumed 55.555s CPU time.
Feb 12 23:23:54 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 12 23:23:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 23:23:55 volumio go-librespot[18500]: time="2026-02-12T23:23:55+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 12 23:23:55 volumio go-librespot[18500]: time="2026-02-12T23:23:55+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 12 23:23:55 volumio go-librespot[18500]: time="2026-02-12T23:23:55+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 12 23:23:55 volumio go-librespot[18500]: time="2026-02-12T23:23:55+07:00" level=info msg="zeroconf server listening on port 40217"
Feb 12 23:23:55 volumio go-librespot[18500]: time="2026-02-12T23:23:55+07:00" level=debug msg="obtained new client token: AABSc6g5M0dlAVEQwgnHmNhNBjGAFnldH/1yvoSV/+oH8yx1Anubhcos2MqEGw5VnsHJMc7Ixpw/6qVkHdND9wLKjPZkKF151yanrhHx6xzbcAuM3rGcv22AxlawIj6QHc6MafS7uacrL/lGsHQfjmZKFi6DYBM4uTYLdI5NxtzvN6AjX7VPABA0nZi1u7ogavRHt+SaGAjIL3fDxt2mPzTEt1J/ZWHL5lvExBisaR0OqX0WgDzuE/ABEQ=="
Feb 12 23:23:55 volumio go-librespot[18500]: time="2026-02-12T23:23:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:23:55 volumio go-librespot[18500]: time="2026-02-12T23:23:55+07:00" level=debug msg="completed keyexchange"
Feb 12 23:23:55 volumio go-librespot[18500]: time="2026-02-12T23:23:55+07:00" level=debug msg="completed challenge"
Feb 12 23:23:55 volumio go-librespot[18500]: time="2026-02-12T23:23:55+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 12 23:23:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:23:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:23:58 volumio volumio[18518]: info: -------------------------------------------
Feb 12 23:23:58 volumio volumio[18518]: info: -----            Volumio3              ----
Feb 12 23:23:58 volumio volumio[18518]: info: -------------------------------------------
Feb 12 23:23:58 volumio volumio[18518]: info: -----          System startup          ----
Feb 12 23:23:58 volumio volumio[18518]: info: -------------------------------------------
Feb 12 23:23:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Feb 12 23:23:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:23:58 volumio go-librespot[18541]: go-librespot daemon starting...
Feb 12 23:23:58 volumio go-librespot[18542]: time="2026-02-12T23:23:58+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:23:58 volumio go-librespot[18542]: time="2026-02-12T23:23:58+07:00" level=debug msg="app state loaded"
Feb 12 23:23:58 volumio go-librespot[18542]: time="2026-02-12T23:23:58+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:23:59 volumio go-librespot[18542]: time="2026-02-12T23:23:59+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 12 23:23:59 volumio go-librespot[18542]: time="2026-02-12T23:23:59+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 12 23:23:59 volumio go-librespot[18542]: time="2026-02-12T23:23:59+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 12 23:23:59 volumio go-librespot[18542]: time="2026-02-12T23:23:59+07:00" level=info msg="zeroconf server listening on port 39885"
Feb 12 23:23:59 volumio go-librespot[18542]: time="2026-02-12T23:23:59+07:00" level=debug msg="obtained new client token: AABObsp9M8zW4qFMalFgFaVLZ6aJ9nccm5Rr7p0UHnKFkrzvN7JC8+3lWg52+V1nQXVKxK+NfWRujP7JATBVsqCz1xImUL6migqyhuh3r6aTlxKtlsDNzHTw6BTYVcuhf4Hax6AoO8ACoS6Tn17+T5ZD7AkLEnt9x8P8enMdhJlbY0+AwKqAo8CqGvj4m8qtuPXW3+rxBbpJF3yLp1eZTiLkWcAgJmwQyrHizXlr6XmVZtD8QmQ7u49GQw=="
Feb 12 23:23:59 volumio volumio-remote-updater[643]: [2026-02-12 23:23:59] [connect] Successful connection
Feb 12 23:23:59 volumio go-librespot[18542]: time="2026-02-12T23:23:59+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 12 23:23:59 volumio go-librespot[18542]: time="2026-02-12T23:23:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 12 23:24:00 volumio go-librespot[18542]: time="2026-02-12T23:24:00+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 12 23:24:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:00 volumio volumio[18518]: info: MYVOLUMIO Environment detected
Feb 12 23:24:00 volumio volumio[18518]: info: Plugin folders cleanup
Feb 12 23:24:00 volumio volumio[18518]: info: Scanning into folder /volumio/app/plugins/
Feb 12 23:24:00 volumio volumio[18518]: info: Scanning category audio_interface
Feb 12 23:24:00 volumio volumio[18518]: info: Scanning category miscellanea
Feb 12 23:24:00 volumio volumio[18518]: info: Scanning category music_service
Feb 12 23:24:00 volumio volumio[18518]: info: Scanning category plugins.json
Feb 12 23:24:00 volumio volumio[18518]: info: Scanning category system_controller
Feb 12 23:24:00 volumio volumio[18518]: info: Scanning category user_interface
Feb 12 23:24:00 volumio volumio[18518]: info: Scanning into folder /data/plugins/
Feb 12 23:24:00 volumio volumio[18518]: info: Scanning category music_service
Feb 12 23:24:00 volumio volumio[18518]: info: Plugin folders cleanup completed
Feb 12 23:24:00 volumio volumio[18518]: info: -------------------------------------------
Feb 12 23:24:00 volumio volumio[18518]: info: -----      Core plugins startup        ----
Feb 12 23:24:00 volumio volumio[18518]: info: -------------------------------------------
Feb 12 23:24:00 volumio volumio[18518]: info: Loading plugins from folder /volumio/app/plugins/
Feb 12 23:24:00 volumio volumio[18518]: info: Adding plugin upnp to MyMusic Plugins
Feb 12 23:24:00 volumio volumio[18518]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 12 23:24:00 volumio volumio[18518]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 12 23:24:00 volumio volumio[18518]: info: Loading plugins from folder /data/plugins/
Feb 12 23:24:00 volumio volumio[18518]: info: Loading plugin "system"...
Feb 12 23:24:00 volumio volumio[18518]: info: Loading plugin "appearance"...
Feb 12 23:24:02 volumio volumio[18518]: info: Loading plugin "network"...
Feb 12 23:24:02 volumio volumio[18518]: info: Refreshing Cached IP Addresses
Feb 12 23:24:02 volumio sudo[18557]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 23:24:02 volumio sudo[18557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:02 volumio sudo[18559]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 23:24:02 volumio volumio[18518]: info: Loading plugin "services"...
Feb 12 23:24:02 volumio sudo[18559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:02 volumio volumio[18518]: info: Loading plugin "alsa_controller"...
Feb 12 23:24:02 volumio sudo[18557]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:02 volumio sudo[18559]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:02 volumio sudo[18566]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 12 23:24:02 volumio sudo[18566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:02 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 23:24:02 volumio volumio[18518]: info: Loading plugin "wizard"...
Feb 12 23:24:02 volumio volumio[18518]: info: Loading plugin "networkfs"...
Feb 12 23:24:02 volumio volumio[18518]: info: Starting Udev Watcher for removable devices
Feb 12 23:24:02 volumio volumio[18518]: info: Ignoring mount for partition: boot
Feb 12 23:24:02 volumio volumio[18518]: info: Ignoring mount for partition: volumio
Feb 12 23:24:02 volumio volumio[18518]: info: Ignoring mount for partition: volumio_data
Feb 12 23:24:02 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 23:24:02 volumio volumio[18518]: info: Loading plugin "volumio_command_line_client"...
Feb 12 23:24:02 volumio volumio[18518]: info: Loading plugin "upnp"...
Feb 12 23:24:02 volumio volumio[18518]: info: [1770913442616] Starting Upmpd Daemon
Feb 12 23:24:02 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 23:24:02 volumio volumio[18518]: info: Loading plugin "my_music"...
Feb 12 23:24:02 volumio volumio[18518]: info: Loading plugin "mpd"...
Feb 12 23:24:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Feb 12 23:24:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:03 volumio go-librespot[18590]: go-librespot daemon starting...
Feb 12 23:24:03 volumio go-librespot[18591]: time="2026-02-12T23:24:03+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:03 volumio go-librespot[18591]: time="2026-02-12T23:24:03+07:00" level=debug msg="app state loaded"
Feb 12 23:24:03 volumio go-librespot[18591]: time="2026-02-12T23:24:03+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:03 volumio volumio[18518]: info: Loading plugin "upnp_browser"...
Feb 12 23:24:03 volumio go-librespot[18591]: time="2026-02-12T23:24:03+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 12 23:24:03 volumio go-librespot[18591]: time="2026-02-12T23:24:03+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 12 23:24:03 volumio go-librespot[18591]: time="2026-02-12T23:24:03+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 12 23:24:03 volumio go-librespot[18591]: time="2026-02-12T23:24:03+07:00" level=info msg="zeroconf server listening on port 44347"
Feb 12 23:24:03 volumio go-librespot[18591]: time="2026-02-12T23:24:03+07:00" level=debug msg="obtained new client token: AAB+BvkgtU9QsamdWe1FdTwrS7CgkMsaS7fOdO7m28aqQNThl04Ihi90CgCrl0IyJ1h630UdoHlRiivTP3bJ92xfKFSi7xgB7lttui3VC3wUKXtO+xtXBokdbgCxKe1VPbsbDbCnKLMokjMKJqpjMkwp3EFuUBA8cndBhbmU9+SfTSBde9tARt+1uUqH0/rSGMjH+TC4oWfBp9+NEErSdkbw4xDRc9OnXjaKSR7h5onukkoY0QZfDKLOug=="
Feb 12 23:24:04 volumio go-librespot[18591]: time="2026-02-12T23:24:04+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 12 23:24:04 volumio go-librespot[18591]: time="2026-02-12T23:24:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 12 23:24:04 volumio go-librespot[18591]: time="2026-02-12T23:24:04+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:04 volumio go-librespot[18591]: time="2026-02-12T23:24:04+07:00" level=debug msg="completed challenge"
Feb 12 23:24:04 volumio go-librespot[18591]: time="2026-02-12T23:24: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 12 23:24:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:05 volumio sudo[18566]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:06 volumio volumio[18518]: info: Starting UPNP Browser
Feb 12 23:24:06 volumio volumio[18518]: info: Loading plugin "alarm-clock"...
Feb 12 23:24:06 volumio volumio[18518]: info: Loading plugin "airplay_emulation"...
Feb 12 23:24:06 volumio volumio[18518]: info: Starting Shairport Sync
Feb 12 23:24:06 volumio volumio[18518]: info: Loading plugin "last_100"...
Feb 12 23:24:06 volumio volumio[18518]: info: Loading plugin "webradio"...
Feb 12 23:24:06 volumio volumio[18518]: info: Loading plugin "i2s_dacs"...
Feb 12 23:24:06 volumio volumio[18518]: info: Loading plugin "volumiodiscovery"...
Feb 12 23:24:06 volumio volumio[18518]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 23:24:06 volumio volumio[18518]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 23:24:06 volumio node[18518]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 23:24:06 volumio volumio[18518]: *** WARNING *** For more information see 
Feb 12 23:24:06 volumio volumio[18518]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 23:24:06 volumio volumio[18518]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 23:24:06 volumio volumio[18518]: *** WARNING *** For more information see 
Feb 12 23:24:06 volumio node[18518]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 23:24:06 volumio node[18518]: *** WARNING *** For more information see 
Feb 12 23:24:06 volumio node[18518]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 23:24:06 volumio node[18518]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 23:24:06 volumio node[18518]: *** WARNING *** For more information see 
Feb 12 23:24:06 volumio volumio[18518]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 12 23:24:06 volumio volumio[18518]: info: Discovery: Started advertising with name: Volumio
Feb 12 23:24:06 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 23:24:06 volumio volumio[18518]: info: Loading plugin "spop"...
Feb 12 23:24:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Feb 12 23:24:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:07 volumio go-librespot[18603]: go-librespot daemon starting...
Feb 12 23:24:07 volumio go-librespot[18604]: time="2026-02-12T23:24:07+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:07 volumio go-librespot[18604]: time="2026-02-12T23:24:07+07:00" level=debug msg="app state loaded"
Feb 12 23:24:07 volumio go-librespot[18604]: time="2026-02-12T23:24:07+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:08 volumio go-librespot[18604]: time="2026-02-12T23:24: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 23:24:08 volumio go-librespot[18604]: time="2026-02-12T23:24:08+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 12 23:24:08 volumio go-librespot[18604]: time="2026-02-12T23:24:08+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 12 23:24:08 volumio go-librespot[18604]: time="2026-02-12T23:24:08+07:00" level=info msg="zeroconf server listening on port 33245"
Feb 12 23:24:08 volumio go-librespot[18604]: time="2026-02-12T23:24:08+07:00" level=debug msg="obtained new client token: AAABseQtPvi58ajIPxSsNmwcARykeC9XR3FVos051WIycIndRAS7AWygYcGSJNchDGxwgvUsvjEjeOs7n77j0mevfpVYy3Kif6LUNYnVqhWFL1owRIaRMyEuXanUA4TBjQthHGx/+LwSP/IG5HDauGMnuuCBc0NQmq7wQXI0/4EnQ71AZH2QEvCYkxBf7QuwFDYQgqjA1RDyFataBEErqnBbuykWCW5on0GT8cKLQH6DYM7YYqdziKdksA=="
Feb 12 23:24:08 volumio go-librespot[18604]: time="2026-02-12T23:24:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:24:08 volumio go-librespot[18604]: time="2026-02-12T23:24:08+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:08 volumio go-librespot[18604]: time="2026-02-12T23:24:08+07:00" level=debug msg="completed challenge"
Feb 12 23:24:08 volumio go-librespot[18604]: time="2026-02-12T23:24:08+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 12 23:24:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:08 volumio volumio[18518]: info: Loading plugin "ytcr"...
Feb 12 23:24:11 volumio volumio[18518]: info: Loading plugin "ytmusic"...
Feb 12 23:24:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Feb 12 23:24:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:11 volumio go-librespot[18612]: go-librespot daemon starting...
Feb 12 23:24:11 volumio go-librespot[18613]: time="2026-02-12T23:24:11+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:11 volumio go-librespot[18613]: time="2026-02-12T23:24:11+07:00" level=debug msg="app state loaded"
Feb 12 23:24:11 volumio go-librespot[18613]: time="2026-02-12T23:24:11+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:12 volumio volumio-remote-updater[643]: [2026-02-12 23:24:12] [connect] Successful connection
Feb 12 23:24:12 volumio go-librespot[18613]: time="2026-02-12T23:24:12+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 12 23:24:12 volumio go-librespot[18613]: time="2026-02-12T23:24:12+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 12 23:24:12 volumio go-librespot[18613]: time="2026-02-12T23:24:12+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 12 23:24:12 volumio go-librespot[18613]: time="2026-02-12T23:24:12+07:00" level=info msg="zeroconf server listening on port 43635"
Feb 12 23:24:12 volumio volumio[18518]: info: Loading plugin "outputs"...
Feb 12 23:24:12 volumio volumio[18518]: info: Loading plugin "albumart"...
Feb 12 23:24:12 volumio volumio[18518]: info: Plugin example_plugin is not enabled
Feb 12 23:24:12 volumio volumio[18518]: info: Loading plugin "inputs"...
Feb 12 23:24:12 volumio volumio[18518]: info: Loading plugin "updater_comm"...
Feb 12 23:24:12 volumio volumio[18518]: info: Plugin mpdemulation is not enabled
Feb 12 23:24:12 volumio volumio[18518]: info: Loading plugin "rest_api"...
Feb 12 23:24:12 volumio go-librespot[18613]: time="2026-02-12T23:24:12+07:00" level=debug msg="obtained new client token: AABhQ+G9GNFmafrxZGGuYQtZjee56rCeXhFtMJjrKH3smifw9ZHfhhMp7ytMLrm9cNiu+rdf4AoBpw3B3PBMi7vgHu5q+3rIAS34cRkrPvaTADsmBoxf/yFS/gbkcE3trtjzQt788u/5vU7G+5g6cAe3llLUOOZUrslHe2/yHMN4iHDQzp9Nj/hgSX7DYm58kVPjlBrlm5u+osUmJ550Obywm7gXcHJT6sbXEee/gebYo6hZqr/7TTUZ4Q=="
Feb 12 23:24:12 volumio volumio[18518]: info: Loading plugin "websocket"...
Feb 12 23:24:12 volumio volumio[18518]: info: Starting Socket.io Server version 1.7.4
Feb 12 23:24:12 volumio volumio[18518]: info: Loading plugin "RoonBridge"...
Feb 12 23:24:12 volumio go-librespot[18613]: time="2026-02-12T23:24:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:24:13 volumio go-librespot[18613]: time="2026-02-12T23:24:13+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:13 volumio go-librespot[18613]: time="2026-02-12T23:24:13+07:00" level=debug msg="completed challenge"
Feb 12 23:24:13 volumio go-librespot[18613]: time="2026-02-12T23:24:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 23:24:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:13 volumio volumio[18518]: info: Applying required configuration parameters for plugin RoonBridge
Feb 12 23:24:13 volumio volumio[18518]: info: Loading i18n strings for locale en
Feb 12 23:24:13 volumio volumio[18518]: Updating browse sources language
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::initPlayerControls
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 23:24:13 volumio volumio[18518]: Express server listening on port 3000
Feb 12 23:24:13 volumio volumio[18518]:  [Metrics]  WebUI:  16s 126.03ms 
Feb 12 23:24:13 volumio volumio[18634]: Forking 3 albumart workers
Feb 12 23:24:13 volumio volumio[18518]: info: CoreStateMachine::resetVolumioState
Feb 12 23:24:13 volumio volumio[18518]: info: CoreStateMachine::getcurrentVolume
Feb 12 23:24:13 volumio volumio[18518]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 23:24:14 volumio sudo[18669]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 23:24:14 volumio sudo[18669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:14 volumio sudo[18669]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:14 volumio sudo[18678]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 23:24:14 volumio sudo[18678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:14 volumio sudo[18678]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:14 volumio volumio[18518]: info: Volumio Network Manager: Network status updated: 1
Feb 12 23:24:14 volumio volumio[18518]: info: VolumeController:: Volume=100 Mute =false
Feb 12 23:24:14 volumio volumio[18518]: info: CoreStateMachine::pushState
Feb 12 23:24:14 volumio volumio[18518]: info: CorePlayQueue::getTrack 0
Feb 12 23:24:14 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 12 23:24:14 volumio volumio[18518]: info: CoreCommandRouter::volumioPushState
Feb 12 23:24:14 volumio volumio[18518]: info: CoreStateMachine::updateTrackBlock
Feb 12 23:24:14 volumio volumio[18518]: info: CorePlayQueue::getTrackBlock
Feb 12 23:24:14 volumio volumio[18518]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 23:24:14 volumio volumio-remote-updater[643]: [2026-02-12 23:24:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770913452 101
Feb 12 23:24:14 volumio volumio[18518]: 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 12 23:24:14 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:14 volumio volumio[18518]: info: Reloading queue from file
Feb 12 23:24:14 volumio volumio[18518]: info: CoreStateMachine::setRepeat null single undefined
Feb 12 23:24:14 volumio volumio[18518]: info: CoreStateMachine::pushState
Feb 12 23:24:14 volumio volumio[18518]: info: CorePlayQueue::getTrack 0
Feb 12 23:24:14 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 12 23:24:14 volumio volumio[18518]: info: CoreCommandRouter::volumioPushState
Feb 12 23:24:14 volumio volumio[18518]: info: CoreStateMachine::setRandom null
Feb 12 23:24:14 volumio volumio[18518]: info: CoreStateMachine::pushState
Feb 12 23:24:14 volumio volumio[18518]: info: CorePlayQueue::getTrack 0
Feb 12 23:24:14 volumio volumio[18518]: info: CoreCommandRouter::volumioPushState
Feb 12 23:24:14 volumio volumio[18518]: info: Setting Device type: Raspberry PI
Feb 12 23:24:14 volumio volumio[18518]: info: Completed loading Core Plugins
Feb 12 23:24:14 volumio volumio[18518]: info: Preparing to generate the ALSA configuration file
Feb 12 23:24:14 volumio volumio[18518]: info: VolumeController:: Volume=100 Mute =false
Feb 12 23:24:14 volumio volumio[18518]: info: CoreStateMachine::pushState
Feb 12 23:24:14 volumio volumio[18518]: info: CorePlayQueue::getTrack 0
Feb 12 23:24:14 volumio volumio[18518]: info: CoreCommandRouter::volumioPushState
Feb 12 23:24:14 volumio volumio[18518]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 23:24:14 volumio volumio[18518]: info: Output device has changed, restarting MPD
Feb 12 23:24:14 volumio volumio[18518]: info: Output device has changed, restarting Shairport Sync
Feb 12 23:24:14 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:14 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:14 volumio sudo[18695]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 12 23:24:14 volumio sudo[18695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:14 volumio sudo[18697]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 23:24:14 volumio volumio[18518]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 23:24:14 volumio sudo[18697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:14 volumio volumio[18518]: info: ___________ START PLUGINS ___________
Feb 12 23:24:14 volumio sudo[18697]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:14 volumio sudo[18699]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 23:24:14 volumio sudo[18699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:14 volumio volumio[18518]: info: ControllerMpd::onStart: Initializing MPD
Feb 12 23:24:14 volumio volumio[18518]: info: Creating MPD Configuration file
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 23:24:15 volumio volumio[18518]: info: [1770913455071] CoreMusicLibrary::Adding element Media Servers
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:24:15 volumio volumio[18518]: info: UPNP Browser: Client initialized successfully
Feb 12 23:24:15 volumio sudo[18695]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:15 volumio sudo[18708]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 23:24:15 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 12 23:24:15 volumio sudo[18708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:15 volumio sudo[18708]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:15 volumio sudo[18710]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 23:24:15 volumio sudo[18710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:15 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 23:24:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 23:24:15 volumio systemd[1]: mpd.service: Consumed 7.141s CPU time.
Feb 12 23:24:15 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 23:24:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 23:24:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 23:24:15 volumio volumio[18518]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 23:24:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 23:24:15 volumio volumio[18518]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 23:24:15 volumio volumio[18518]: info: [1770913455429] CoreMusicLibrary::Adding element Last_100
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 23:24:15 volumio volumio[18518]: info: [1770913455449] CoreMusicLibrary::Adding element Webradio
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:24:15 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 23:24:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 23:24:15 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 23:24:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 23:24:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 23:24:15 volumio volumio[18518]: info: Initializing BBC Radios
Feb 12 23:24:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 23:24:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:15 volumio volumio[18518]: info: Creating Spotify config file
Feb 12 23:24:15 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:16 volumio sudo[18728]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 23:24:16 volumio sudo[18728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 23:24:16 volumio sudo[18728]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20.
Feb 12 23:24:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:16 volumio go-librespot[18740]: go-librespot daemon starting...
Feb 12 23:24:16 volumio go-librespot[18741]: time="2026-02-12T23:24:16+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:17 volumio volumio[18647]: Starting albumart workers
Feb 12 23:24:17 volumio go-librespot[18741]: time="2026-02-12T23:24:17+07:00" level=info msg="zeroconf server listening on port 42007"
Feb 12 23:24:17 volumio volumio[18518]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 23:24:17 volumio volumio[18518]: info: [1770913457231] CoreMusicLibrary::Adding element YouTube Music
Feb 12 23:24:17 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 23:24:17 volumio volumio[18518]: Cannot find translation for source YouTube Music
Feb 12 23:24:17 volumio volumio[18648]: Starting albumart workers
Feb 12 23:24:17 volumio volumio[18518]: info: Volumio Calling Home
Feb 12 23:24:17 volumio volumio[18650]: Starting albumart workers
Feb 12 23:24:17 volumio sudo[18749]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 12 23:24:17 volumio sudo[18749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:17 volumio sudo[18749]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:18 volumio volumio[18518]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 12 23:24:18 volumio volumio[18518]: info: Discovery: Found device Volumio
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::volumioGetState
Feb 12 23:24:18 volumio volumio[18518]: info: CorePlayQueue::getTrack 0
Feb 12 23:24:18 volumio volumio[18518]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 12 23:24:18 volumio volumio[18518]: info: Discovery: Found device Volumio
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::volumioGetState
Feb 12 23:24:18 volumio volumio[18518]: info: CorePlayQueue::getTrack 0
Feb 12 23:24:18 volumio volumio[18518]: info: MPD Permissions set
Feb 12 23:24:18 volumio volumio[18518]: info: MPD Permissions set
Feb 12 23:24:18 volumio volumio[18518]: info: Upmpdcli Daemon Started
Feb 12 23:24:18 volumio volumio[18518]: info: Spotify config file written
Feb 12 23:24:18 volumio volumio[18518]: 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 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio sudo[18755]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 12 23:24:18 volumio sudo[18755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 12 23:24:18 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 12 23:24:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:18 volumio volumio[18518]: info: No need to fix Spotify hosts
Feb 12 23:24:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:18 volumio go-librespot[18763]: go-librespot daemon starting...
Feb 12 23:24:18 volumio sudo[18755]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:19 volumio go-librespot[18775]: time="2026-02-12T23:24:19+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:19 volumio go-librespot[18775]: time="2026-02-12T23:24:19+07:00" level=debug msg="app state loaded"
Feb 12 23:24:19 volumio go-librespot[18775]: time="2026-02-12T23:24:19+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:19 volumio go-librespot[18775]: time="2026-02-12T23:24:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 23:24:19 volumio go-librespot[18775]: time="2026-02-12T23:24:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 12 23:24:19 volumio go-librespot[18775]: time="2026-02-12T23:24:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 12 23:24:19 volumio go-librespot[18775]: time="2026-02-12T23:24:19+07:00" level=info msg="zeroconf server listening on port 33709"
Feb 12 23:24:19 volumio volumio[18518]: info: Volumio called home
Feb 12 23:24:19 volumio go-librespot[18775]: time="2026-02-12T23:24:19+07:00" level=debug msg="obtained new client token: AAAdfCNWrsYu8GmfzkEgHUEg7W15ckCI4JOuTYS1Cuznj0x0wkuEgvTGhVNtv8dDLiVkOqemfoIeKRetOHuU5jcdJOrcboinOJ1kH1TUrZke0aUTgJNThL8aNoBmFmP48m1bOENWXdgxph5QX0BMb5zAEO7AAprzq4SPQLsB1okvwYZ14f27YQJUqi9bmu2zZ4lohVFNtk1SmlUAn7iJ/hreNEC81xIsVejJCVb+7eVUZX9kyWwtxVELLQ=="
Feb 12 23:24:19 volumio volumio[18518]: info: Starting Shairport Sync
Feb 12 23:24:19 volumio volumio[18518]: info: Starting Shairport Sync
Feb 12 23:24:20 volumio volumio[18518]: info: Starting Shairport Sync
Feb 12 23:24:20 volumio sudo[18794]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 23:24:20 volumio sudo[18794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:20 volumio sudo[18796]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 23:24:20 volumio sudo[18796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:20 volumio go-librespot[18775]: time="2026-02-12T23:24:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:24:20 volumio sudo[18798]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 23:24:20 volumio sudo[18798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 23:24:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 23:24:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 23:24:20 volumio systemd[1]: shairport-sync.service: Consumed 2.299s CPU time.
Feb 12 23:24:20 volumio go-librespot[18775]: time="2026-02-12T23:24:20+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:20 volumio go-librespot[18775]: time="2026-02-12T23:24:20+07:00" level=debug msg="completed challenge"
Feb 12 23:24:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 23:24:20 volumio sudo[18794]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:20 volumio go-librespot[18775]: time="2026-02-12T23:24:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 23:24:20 volumio volumio[18518]: info: An error occurred while refreshing Spotify Token Error: Bad Request
Feb 12 23:24:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:20 volumio volumio[18518]: info: Shairport-Sync Started
Feb 12 23:24:20 volumio volumio[18518]: Error adding Membership: Error: addMembership EINVAL
Feb 12 23:24:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 23:24:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 23:24:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 23:24:20 volumio volumio[18518]: info: CoreCommandRouter::volumioGetState
Feb 12 23:24:20 volumio volumio[18518]: info: CorePlayQueue::getTrack 0
Feb 12 23:24:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 23:24:20 volumio sudo[18798]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:20 volumio sudo[18796]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:20 volumio volumio[18518]: info: Shairport-Sync Started
Feb 12 23:24:20 volumio volumio[18518]: info: Shairport-Sync Started
Feb 12 23:24:21 volumio volumio[18518]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 12 23:24:21 volumio volumio[18518]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 23:24:21 volumio volumio[18518]: info: VolumeController:: Volume=100 Mute =false
Feb 12 23:24:21 volumio volumio[18518]: info: CoreCommandRouter::volumioGetState
Feb 12 23:24:21 volumio volumio[18518]: info: CorePlayQueue::getTrack 0
Feb 12 23:24:21 volumio volumio[18518]: info: CoreStateMachine::pushState
Feb 12 23:24:21 volumio volumio[18518]: info: CorePlayQueue::getTrack 0
Feb 12 23:24:21 volumio volumio[18518]: info: CoreCommandRouter::volumioPushState
Feb 12 23:24:22 volumio volumio[18518]: info: go-librespot daemon successfully initialized
Feb 12 23:24:23 volumio mpd[18739]: 2026-02-12T23:24:23 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 12 23:24:23 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 12 23:24:23 volumio sudo[18699]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:23 volumio sudo[18710]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:23 volumio volumio[18518]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 23:24:23 volumio volumio[18518]:   assert.ok(self.idling)
Feb 12 23:24:23 volumio volumio[18518]: error: The expression evaluated to a falsy value:
Feb 12 23:24:23 volumio volumio[18518]:   assert.ok(self.idling)
Feb 12 23:24:23 volumio volumio[18518]: info: MPD running with PID18739
Feb 12 23:24:23 volumio volumio[18518]:  ,establishing connection
Feb 12 23:24:23 volumio volumio[18518]: error: updateQueue error: null
Feb 12 23:24:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 12 23:24:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:23 volumio volumio[18518]: info: Completed starting Core Plugins
Feb 12 23:24:23 volumio volumio[18518]: info: -------------------------------------------
Feb 12 23:24:23 volumio volumio[18518]: info: -----    MyVolumio plugins startup     ----
Feb 12 23:24:23 volumio volumio[18518]: info: -------------------------------------------
Feb 12 23:24:23 volumio volumio[18518]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 12 23:24:23 volumio volumio[18518]: error: updateQueue error: null
Feb 12 23:24:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:23 volumio go-librespot[18852]: go-librespot daemon starting...
Feb 12 23:24:23 volumio go-librespot[18853]: time="2026-02-12T23:24:23+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:23 volumio go-librespot[18853]: time="2026-02-12T23:24:23+07:00" level=debug msg="app state loaded"
Feb 12 23:24:23 volumio go-librespot[18853]: time="2026-02-12T23:24:23+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:24 volumio go-librespot[18853]: time="2026-02-12T23:24:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 23:24:24 volumio go-librespot[18853]: time="2026-02-12T23:24:24+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 12 23:24:24 volumio go-librespot[18853]: time="2026-02-12T23:24:24+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 12 23:24:24 volumio go-librespot[18853]: time="2026-02-12T23:24:24+07:00" level=info msg="zeroconf server listening on port 37851"
Feb 12 23:24:24 volumio go-librespot[18853]: time="2026-02-12T23:24:24+07:00" level=debug msg="obtained new client token: AABqJ7dSO71U36wahZMn0uTKqlUIIfINtQHZf6o+UbAF6h12GZo5oK2bT3p6C47nEX58zQws+17fBRh6ZWrmOU52R6iU/mXqXPm1/m53Mo3kYmwwVZEaV3HlOOyQ9MOXTI4TA3pUtpFup0vezvHsntZ16GRbRLRxdJ65rSLAtr9/lad5KfvVHvIIfud4YYZe8o4F/tOeoMW14Uh1AyJsHuwgjMkYzu+5mm79IXcnDquBzEuo672ocNArng=="
Feb 12 23:24:24 volumio go-librespot[18853]: time="2026-02-12T23:24:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:24:24 volumio go-librespot[18853]: time="2026-02-12T23:24:24+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:24 volumio go-librespot[18853]: time="2026-02-12T23:24:24+07:00" level=debug msg="completed challenge"
Feb 12 23:24:24 volumio go-librespot[18853]: time="2026-02-12T23:24:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 23:24:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:25 volumio volumio[18518]: info: Initializing connection to go-librespot Websocket
Feb 12 23:24:25 volumio volumio[18518]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:24:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 12 23:24:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:27 volumio go-librespot[18860]: go-librespot daemon starting...
Feb 12 23:24:27 volumio go-librespot[18861]: time="2026-02-12T23:24:27+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:27 volumio go-librespot[18861]: time="2026-02-12T23:24:27+07:00" level=debug msg="app state loaded"
Feb 12 23:24:27 volumio go-librespot[18861]: time="2026-02-12T23:24:27+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:28 volumio volumio[18518]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 12 23:24:28 volumio go-librespot[18861]: time="2026-02-12T23:24:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 23:24:28 volumio go-librespot[18861]: time="2026-02-12T23:24:28+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 12 23:24:28 volumio go-librespot[18861]: time="2026-02-12T23:24:28+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 12 23:24:28 volumio go-librespot[18861]: time="2026-02-12T23:24:28+07:00" level=info msg="zeroconf server listening on port 40409"
Feb 12 23:24:28 volumio go-librespot[18861]: time="2026-02-12T23:24:28+07:00" level=debug msg="obtained new client token: AAD2BgAlIfVSXyjiF9P7Qmd32aUdGwUohVR7RcYK4pbPgCM5/w27HBP4HeZOwCdMsi+ZJLpove+DiiLdm+DbpB9iMSziIOBGNLD5EGPoWdDhf2BMbXv1xhT3pFw2gK7RICevgPs4KbPefXDT1N5ptXqFJr/Kf5nxk6I6DRsqN5ex/NNSMvrieMJvkldN/01658PzhHAz+n8aajlkM/4iyyRKFKFe3Lv+3fgmSQNECjgkq6eVyJailmJ+PA=="
Feb 12 23:24:28 volumio go-librespot[18861]: time="2026-02-12T23:24:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:24:28 volumio go-librespot[18861]: time="2026-02-12T23:24:28+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:28 volumio go-librespot[18861]: time="2026-02-12T23:24:28+07:00" level=debug msg="completed challenge"
Feb 12 23:24:28 volumio volumio[18518]: info: Initializing connection to go-librespot Websocket
Feb 12 23:24:28 volumio go-librespot[18861]: time="2026-02-12T23:24:28+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 12 23:24:28 volumio volumio[18518]: info: Error connecting to go-librespot Websocket: Error: read ECONNRESET
Feb 12 23:24:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:31 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Feb 12 23:24:31 volumio volumio[18518]: info: Initializing connection to go-librespot Websocket
Feb 12 23:24:31 volumio volumio[18518]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:24:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 12 23:24:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:32 volumio go-librespot[18883]: go-librespot daemon starting...
Feb 12 23:24:32 volumio go-librespot[18885]: time="2026-02-12T23:24:32+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:32 volumio go-librespot[18885]: time="2026-02-12T23:24:32+07:00" level=debug msg="app state loaded"
Feb 12 23:24:32 volumio go-librespot[18885]: time="2026-02-12T23:24:32+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 12 23:24:32 volumio volumio[18518]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 12 23:24:32 volumio volumio[18518]: info: Adding plugin multiroom to MyMusic Plugins
Feb 12 23:24:32 volumio volumio[18518]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 12 23:24:32 volumio volumio[18518]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 12 23:24:32 volumio volumio[18518]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 12 23:24:32 volumio volumio[18518]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 12 23:24:32 volumio volumio[18518]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 12 23:24:32 volumio volumio[18518]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 12 23:24:32 volumio go-librespot[18885]: time="2026-02-12T23:24:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 12 23:24:32 volumio go-librespot[18885]: time="2026-02-12T23:24:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 12 23:24:32 volumio go-librespot[18885]: time="2026-02-12T23:24:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 12 23:24:32 volumio go-librespot[18885]: time="2026-02-12T23:24:32+07:00" level=info msg="zeroconf server listening on port 33603"
Feb 12 23:24:32 volumio go-librespot[18885]: time="2026-02-12T23:24:32+07:00" level=debug msg="obtained new client token: AAAPQQdAAJ52+xXF8tIn8h/giFHpK6G7PH3AGsLb133diofH42/H0yx11mV3GBpX6Z69JS4OzxX3ciolGf4CqfwQmPg8agnG0KdTnU3nFUYY75EBfxO6igPfs6+/HfXqtqKOqDv1iWH4i9DdyJikx9LmLOTiOhugNDyOA28teZw137O9H29UTit1j/d1yicpLEFYX8a+GxNaFILS2X5ZfZdIvCL+HzF93JcNY/XGAzPzVm5YKN14DIasbA=="
Feb 12 23:24:33 volumio go-librespot[18885]: time="2026-02-12T23:24:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:24:33 volumio go-librespot[18885]: time="2026-02-12T23:24:33+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:33 volumio go-librespot[18885]: time="2026-02-12T23:24:33+07:00" level=debug msg="completed challenge"
Feb 12 23:24:33 volumio go-librespot[18885]: time="2026-02-12T23:24:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 23:24:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:33 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully.
Feb 12 23:24:33 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Feb 12 23:24:33 volumio systemd[1]: setdatetime-helper.service: Consumed 1.881s CPU time.
Feb 12 23:24:34 volumio volumio[18518]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 12 23:24:34 volumio volumio[18518]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 12 23:24:34 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:34 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:34 volumio volumio[18518]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 12 23:24:34 volumio volumio[18518]: info: MyVolumio login type: Token
Feb 12 23:24:34 volumio volumio[18518]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 12 23:24:34 volumio volumio[18518]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 12 23:24:36 volumio volumio[18518]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 12 23:24:36 volumio volumio[18518]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 12 23:24:36 volumio volumio[18518]: info: Streaming services startup
Feb 12 23:24:36 volumio volumio[18518]: info: Starting Streaming Daemon
Feb 12 23:24:36 volumio sudo[18922]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 23:24:36 volumio volumio[18518]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 12 23:24:36 volumio sudo[18922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:36 volumio sudo[18922]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:36 volumio volumio[18518]: info: Initializing connection to go-librespot Websocket
Feb 12 23:24:36 volumio volumio[18518]: error: Cannot start Volumio Streaming Daemon
Feb 12 23:24:36 volumio volumio[18518]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 12 23:24:36 volumio volumio[18518]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 12 23:24:36 volumio volumio[18518]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:24:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 12 23:24:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:36 volumio go-librespot[18928]: go-librespot daemon starting...
Feb 12 23:24:36 volumio go-librespot[18929]: time="2026-02-12T23:24:36+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:36 volumio go-librespot[18929]: time="2026-02-12T23:24:36+07:00" level=debug msg="app state loaded"
Feb 12 23:24:36 volumio go-librespot[18929]: time="2026-02-12T23:24:36+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:37 volumio go-librespot[18929]: time="2026-02-12T23:24:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 12 23:24:37 volumio go-librespot[18929]: time="2026-02-12T23:24:37+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 12 23:24:37 volumio go-librespot[18929]: time="2026-02-12T23:24:37+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 12 23:24:37 volumio go-librespot[18929]: time="2026-02-12T23:24:37+07:00" level=info msg="zeroconf server listening on port 34323"
Feb 12 23:24:37 volumio volumio[18518]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 12 23:24:37 volumio go-librespot[18929]: time="2026-02-12T23:24:37+07:00" level=debug msg="obtained new client token: AABlvToG1uAnZW3WUkZqYa3zb8DdtySB0cAngYDqs0LI+yHfd7o6jCmtRwUmUB72kV6EF0CKicFC5OefVRSVoxtmth4CcrJBfd/6mFoJzux3iw3TfpvmGjeJbKapURMByTHpEU0wkXuakDkFn09JTha2cb7MHeBn+wUrSPdH3UHHCWUb6RNxaz7y7JbKyAyehHz19IaU1LI4Xjmx/HhYD8P5DITJ3+bTHMAp7Dnqt6lHWDrcSzHsSgQaUw=="
Feb 12 23:24:37 volumio go-librespot[18929]: time="2026-02-12T23:24:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:24:37 volumio go-librespot[18929]: time="2026-02-12T23:24:37+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:37 volumio go-librespot[18929]: time="2026-02-12T23:24:37+07:00" level=debug msg="completed challenge"
Feb 12 23:24:37 volumio go-librespot[18929]: time="2026-02-12T23:24:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 23:24:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:38 volumio volumio[18518]: info: MyVolumio token set successfully
Feb 12 23:24:38 volumio volumio[18518]: info: MYVOLUMIO: Adding device
Feb 12 23:24:38 volumio volumio[18518]: info: MYVOLUMIO: Evaluating Server
Feb 12 23:24:38 volumio volumio[18518]: info: MyVolumio status changed
Feb 12 23:24:38 volumio volumio[18518]: info: Streaming services startup
Feb 12 23:24:38 volumio volumio[18518]: info: Starting Streaming Daemon
Feb 12 23:24:38 volumio volumio[18518]: info: Removing browser output: myVolumio user plan is not superstar
Feb 12 23:24:38 volumio volumio[18518]: info: Removing audio output:
Feb 12 23:24:38 volumio volumio[18518]: info: Stoppping Tunnel 1
Feb 12 23:24:38 volumio sudo[18958]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 23:24:38 volumio sudo[18958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:38 volumio sudo[18958]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:38 volumio sudo[18961]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 12 23:24:38 volumio sudo[18961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:38 volumio volumio[18518]: error: Cannot start Volumio Streaming Daemon
Feb 12 23:24:38 volumio volumio[18518]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 12 23:24:38 volumio volumio[18518]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 12 23:24:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 23:24:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 23:24:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 23:24:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 23:24:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 23:24:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 23:24:38 volumio volumio[18518]: info: Setting Geolocation for MyVolumio to as1
Feb 12 23:24:38 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:38 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:38 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 23:24:38 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 23:24:39 volumio sudo[18961]: pam_unix(sudo:session): session closed for user root
Feb 12 23:24:39 volumio volumio[18518]: info: Remote SSH Stopped
Feb 12 23:24:39 volumio volumio[18518]: info: Initializing connection to go-librespot Websocket
Feb 12 23:24:39 volumio volumio[18518]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:24:40 volumio volumio[18518]: info: Updating MyVolumio device info
Feb 12 23:24:40 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:40 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:40 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:40 volumio volumio[18518]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 12 23:24:40 volumio volumio[18518]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 12 23:24:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 12 23:24:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:41 volumio go-librespot[18963]: go-librespot daemon starting...
Feb 12 23:24:41 volumio go-librespot[18964]: time="2026-02-12T23:24:41+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:41 volumio go-librespot[18964]: time="2026-02-12T23:24:41+07:00" level=debug msg="app state loaded"
Feb 12 23:24:41 volumio go-librespot[18964]: time="2026-02-12T23:24:41+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:41 volumio go-librespot[18964]: time="2026-02-12T23:24:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 12 23:24:41 volumio go-librespot[18964]: time="2026-02-12T23:24:41+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 12 23:24:41 volumio go-librespot[18964]: time="2026-02-12T23:24:41+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 12 23:24:41 volumio go-librespot[18964]: time="2026-02-12T23:24:41+07:00" level=info msg="zeroconf server listening on port 40249"
Feb 12 23:24:41 volumio go-librespot[18964]: time="2026-02-12T23:24:41+07:00" level=debug msg="obtained new client token: AACUFJ26Bu9NT/X03ca25dkjND8QnjEv+UCNmeUvd0v88fBWNhjk6Te+exviOoTNCWHXnlNguizIRXpLSXFmPE+QT33divC4iIgRePjJeBRNlvMofNUF8Tu4sWZ1rcDTG6nEBdKvfx8kW7/L+PoqeYHst2w0vGNyZD0yRvHoRQlmXxrFKVKdt+fm9v9byIIbnzNpKe4AUNg96ennbXweMBMf9URU3c1uHXo/vRHsH7Znqo8+RnMOKksB+g=="
Feb 12 23:24:41 volumio go-librespot[18964]: time="2026-02-12T23:24:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:24:42 volumio go-librespot[18964]: time="2026-02-12T23:24:42+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:42 volumio go-librespot[18964]: time="2026-02-12T23:24:42+07:00" level=debug msg="completed challenge"
Feb 12 23:24:42 volumio go-librespot[18964]: time="2026-02-12T23:24:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 23:24:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:42 volumio volumio[18518]: info: Initializing connection to go-librespot Websocket
Feb 12 23:24:42 volumio volumio[18518]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:24:44 volumio volumio[18518]: info: MYVOLUMIO: Adding device
Feb 12 23:24:44 volumio volumio[18518]: info: MYVOLUMIO: Evaluating Server
Feb 12 23:24:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 12 23:24:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:45 volumio volumio[18518]: info: Setting Geolocation for MyVolumio to as1
Feb 12 23:24:45 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:45 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:45 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:45 volumio volumio[18518]: info: Initializing connection to go-librespot Websocket
Feb 12 23:24:45 volumio volumio[18518]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:24:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:45 volumio go-librespot[19004]: go-librespot daemon starting...
Feb 12 23:24:45 volumio go-librespot[19005]: time="2026-02-12T23:24:45+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:45 volumio go-librespot[19005]: time="2026-02-12T23:24:45+07:00" level=debug msg="app state loaded"
Feb 12 23:24:45 volumio go-librespot[19005]: time="2026-02-12T23:24:45+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:45 volumio volumio[18518]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 12 23:24:45 volumio go-librespot[19005]: time="2026-02-12T23:24:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 23:24:45 volumio go-librespot[19005]: time="2026-02-12T23:24:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 12 23:24:45 volumio go-librespot[19005]: time="2026-02-12T23:24:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 12 23:24:45 volumio go-librespot[19005]: time="2026-02-12T23:24:45+07:00" level=info msg="zeroconf server listening on port 44287"
Feb 12 23:24:46 volumio go-librespot[19005]: time="2026-02-12T23:24:46+07:00" level=debug msg="obtained new client token: AABD/5FKspUScxBIXX9dKPWCBIYeQW+sP8h6O+REBlGXZ1RaOpZIMmqVzp+pQ2UniG2gXUUIGwkUwrYBqYbc8/GLKHMaW4y5AoNEGf+FLtODP8qrdQtFLNNDTHyPkQLwwHWFxYD/9N5fV3xfkMIyfDcKDG3DoxYMRQh7TtP+MAcWYcYAfnUqlk81+poby122mdhl6YYULoCqNugRPu967vvRQdcUNMxKGFTdpZzs2Y0LejMRFwhq0jA="
Feb 12 23:24:46 volumio go-librespot[19005]: time="2026-02-12T23:24:46+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 12 23:24:46 volumio go-librespot[19005]: time="2026-02-12T23:24:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 12 23:24:46 volumio volumio[18518]: info: Updating MyVolumio device info
Feb 12 23:24:46 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:46 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:46 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:46 volumio go-librespot[19005]: time="2026-02-12T23:24:46+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:46 volumio go-librespot[19005]: time="2026-02-12T23:24:46+07:00" level=debug msg="completed challenge"
Feb 12 23:24:46 volumio go-librespot[19005]: time="2026-02-12T23:24:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 23:24:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:46 volumio volumio[18518]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 12 23:24:47 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 23:24:47 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:47 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 12 23:24:47 volumio volumio-remote-updater[643]: Test mode disabled
Feb 12 23:24:47 volumio volumio-remote-updater[643]: Alpha mode disabled
Feb 12 23:24:47 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled
Feb 12 23:24:47 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 12 23:24:48 volumio volumio[18518]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for CPU utilization spike
\nFix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\nAdd BLE onboarding plugin
\nEnable vc4-kms-v3d for all compatible RPi models
\nUpdate Tidal SDK
\n\n","title":"Update v4.096","updateavailable":true}
Feb 12 23:24:48 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 12 23:24:48 volumio volumio[18518]: info: Initializing connection to go-librespot Websocket
Feb 12 23:24:48 volumio volumio[18518]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:24:49 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 12 23:24:49 volumio volumio[18518]: 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 12 23:24:49 volumio volumio[18518]: info: CoreCommandRouter::volumioGetState
Feb 12 23:24:49 volumio volumio[18518]: info: CorePlayQueue::getTrack 0
Feb 12 23:24:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 12 23:24:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:49 volumio go-librespot[19016]: go-librespot daemon starting...
Feb 12 23:24:49 volumio go-librespot[19017]: time="2026-02-12T23:24:49+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:49 volumio go-librespot[19017]: time="2026-02-12T23:24:49+07:00" level=debug msg="app state loaded"
Feb 12 23:24:49 volumio go-librespot[19017]: time="2026-02-12T23:24:49+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:50 volumio go-librespot[19017]: time="2026-02-12T23:24:50+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 12 23:24:50 volumio go-librespot[19017]: time="2026-02-12T23:24:50+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 12 23:24:50 volumio go-librespot[19017]: time="2026-02-12T23:24:50+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 12 23:24:50 volumio go-librespot[19017]: time="2026-02-12T23:24:50+07:00" level=info msg="zeroconf server listening on port 45011"
Feb 12 23:24:50 volumio go-librespot[19017]: time="2026-02-12T23:24:50+07:00" level=debug msg="obtained new client token: AABpWzykbm4yiidHwEyQlURjo+ZGua9xTdxKRs8oZVs7Q7MAoplbgRJuukFp11nyAshiib3LaGbavuBz3T85KMJWBqJiaBfR2A5FA5GWIgMT+6yYsE0pYp20U+06K629Eu9/bWuwAr7SzpYhP/zijrpg3L7205MciGbi+VEJgXw+DRyFErEmD3qA8yPWLB7R7xwl3r17Gim3OPGEEi0wn6GNt8u+Yln5s6c8nHAJK6uz/YkyZXeCwZ7Lpw=="
Feb 12 23:24:50 volumio go-librespot[19017]: time="2026-02-12T23:24:50+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 12 23:24:50 volumio go-librespot[19017]: time="2026-02-12T23:24:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 12 23:24:50 volumio go-librespot[19017]: time="2026-02-12T23:24:50+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:50 volumio go-librespot[19017]: time="2026-02-12T23:24:50+07:00" level=debug msg="completed challenge"
Feb 12 23:24:50 volumio go-librespot[19017]: time="2026-02-12T23:24:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 12 23:24:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:51 volumio volumio[18518]: info: Initializing connection to go-librespot Websocket
Feb 12 23:24:51 volumio volumio[18518]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:24:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 12 23:24:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:54 volumio go-librespot[19039]: go-librespot daemon starting...
Feb 12 23:24:54 volumio go-librespot[19040]: time="2026-02-12T23:24:54+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:54 volumio go-librespot[19040]: time="2026-02-12T23:24:54+07:00" level=debug msg="app state loaded"
Feb 12 23:24:54 volumio go-librespot[19040]: time="2026-02-12T23:24:54+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:54 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:54 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:54 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Feb 12 23:24:54 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Feb 12 23:24:54 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Feb 12 23:24:54 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Feb 12 23:24:54 volumio volumio[18518]: info: CoreCommandRouter::volumioGetBrowseSources
Feb 12 23:24:54 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 23:24:54 volumio volumio[18518]: info: Initializing connection to go-librespot Websocket
Feb 12 23:24:54 volumio go-librespot[19040]: time="2026-02-12T23:24:54+07:00" level=debug msg="new websocket client"
Feb 12 23:24:54 volumio volumio[18518]: info: Connection to go-librespot Websocket established
Feb 12 23:24:54 volumio go-librespot[19040]: time="2026-02-12T23:24:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 12 23:24:54 volumio go-librespot[19040]: time="2026-02-12T23:24:54+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 12 23:24:54 volumio go-librespot[19040]: time="2026-02-12T23:24:54+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 12 23:24:54 volumio go-librespot[19040]: time="2026-02-12T23:24:54+07:00" level=info msg="zeroconf server listening on port 35387"
Feb 12 23:24:54 volumio go-librespot[19040]: time="2026-02-12T23:24:54+07:00" level=debug msg="obtained new client token: AAAwmYylZqF/EBw+OvlqFml1nOiz/McpEH/vsxCp+nU8+MmYSLbfGDdoR0mo//fyOr0I1krPj1/qaAniHUb8K4qliUfe45tQkqrQDwYykrH4shNrResbTqzKjub5iYWmYw65d4t3W4vmNlQHXSmMBczS3a8KM0ROnxCURuCSmLJS/yZrHa53rciC3/CnM2wWhYQCL+u8isHwHnz7XwKW/ngD156RBp0rvSSQotFZ7+kr+F43pludaDat5w=="
Feb 12 23:24:55 volumio go-librespot[19040]: time="2026-02-12T23:24:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 12 23:24:55 volumio go-librespot[19040]: time="2026-02-12T23:24:55+07:00" level=debug msg="completed keyexchange"
Feb 12 23:24:55 volumio go-librespot[19040]: time="2026-02-12T23:24:55+07:00" level=debug msg="completed challenge"
Feb 12 23:24:55 volumio go-librespot[19040]: time="2026-02-12T23:24:55+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 12 23:24:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 23:24:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 23:24:55 volumio volumio[18518]: info: Connection to go-librespot Websocket closed
Feb 12 23:24:56 volumio volumio[18518]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Feb 12 23:24:56 volumio volumio[18518]: info: Completed starting MyVolumio Plugin
Feb 12 23:24:56 volumio volumio[18518]:  [Metrics]  CommandRouter:  57s 611.32ms 
Feb 12 23:24:56 volumio volumio[18518]: info: CoreCommandRouter::volumiosetStartupVolume
Feb 12 23:24:56 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 23:24:56 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 23:24:56 volumio volumio[18518]: info: CoreCommandRouter::Close All Modals sent
Feb 12 23:24:56 volumio volumio[18518]: info: CoreCommandRouter::Close All Modals sent
Feb 12 23:24:57 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Feb 12 23:24:57 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Feb 12 23:24:57 volumio volumio[18518]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Feb 12 23:24:57 volumio volumio[18518]: info: Getting Spotify volume
Feb 12 23:24:57 volumio volumio[18518]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 23:24:57 volumio volumio[18518]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 23:24:57 volumio volumio[18518]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 12 23:24:57 volumio volumio[18518]:   errno: -111,
Feb 12 23:24:57 volumio volumio[18518]:   code: 'ECONNREFUSED',
Feb 12 23:24:57 volumio volumio[18518]:   syscall: 'connect',
Feb 12 23:24:57 volumio volumio[18518]:   address: '127.0.0.1',
Feb 12 23:24:57 volumio volumio[18518]:   port: 9879,
Feb 12 23:24:57 volumio volumio[18518]:   response: undefined
Feb 12 23:24:57 volumio volumio[18518]: }
Feb 12 23:24:57 volumio volumio[18518]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 23:24:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 12 23:24:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 23:24:58 volumio go-librespot[19061]: go-librespot daemon starting...
Feb 12 23:24:58 volumio go-librespot[19062]: time="2026-02-12T23:24:58+07:00" level=info msg="running go-librespot 0.4.0"
Feb 12 23:24:58 volumio go-librespot[19062]: time="2026-02-12T23:24:58+07:00" level=debug msg="app state loaded"
Feb 12 23:24:58 volumio go-librespot[19062]: time="2026-02-12T23:24:58+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 23:24:58 volumio sudo[19070]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 23:23'
Feb 12 23:24:58 volumio sudo[19070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 23:24:59 volumio go-librespot[19062]: time="2026-02-12T23:24:59+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 12 23:24:59 volumio go-librespot[19062]: time="2026-02-12T23:24:59+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 12 23:24:59 volumio go-librespot[19062]: time="2026-02-12T23:24:59+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 12 23:24:59 volumio go-librespot[19062]: time="2026-02-12T23:24:59+07:00" level=info msg="zeroconf server listening on port 34219"
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"