Feb 09 04:42:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 04:42:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:00 volumio go-librespot[20918]: go-librespot daemon starting... Feb 09 04:42:00 volumio go-librespot[20919]: time="2026-02-09T04:42:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:00 volumio go-librespot[20919]: time="2026-02-09T04:42:00+07:00" level=debug msg="app state loaded" Feb 09 04:42:00 volumio go-librespot[20919]: time="2026-02-09T04:42:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:00 volumio volumio[20582]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 04:42:00 volumio go-librespot[20919]: time="2026-02-09T04:42:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 04:42:00 volumio go-librespot[20919]: time="2026-02-09T04:42:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 09 04:42:00 volumio go-librespot[20919]: time="2026-02-09T04:42:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 09 04:42:00 volumio go-librespot[20919]: time="2026-02-09T04:42:00+07:00" level=info msg="zeroconf server listening on port 45361" Feb 09 04:42:00 volumio go-librespot[20919]: time="2026-02-09T04:42:00+07:00" level=debug msg="obtained new client token: AACTTWVOW8njzwB6GBfAZVDYRevYcu2omQNSb7gckLryx96OQxGaTSQeB54dGWXLQlQsnTcRL2a2Gg6RZOPAbHfuLPg4/E0zCD7c6fC099wSF2LRN0rrvUo1Y6wQg99MA6hDzRC5jvlRhjJ8YkwykI1+2xM8yq1+X5G4KXsIZxbSWdu8Yc8FenMqFK8z/O/XKnImKjxGao6pBpUwr0OGqknYIVjjb+s69d61FIqK86M+5+9SOQPdLlijXw==" Feb 09 04:42:00 volumio go-librespot[20919]: time="2026-02-09T04:42:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:01 volumio go-librespot[20919]: time="2026-02-09T04:42:01+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:01 volumio go-librespot[20919]: time="2026-02-09T04:42:01+07:00" level=debug msg="completed challenge" Feb 09 04:42:01 volumio go-librespot[20919]: time="2026-02-09T04:42:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:42:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:01 volumio volumio[20582]: info: Initializing connection to go-librespot Websocket Feb 09 04:42:01 volumio volumio[20582]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:42:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 04:42:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 04:42:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:04 volumio go-librespot[20929]: go-librespot daemon starting... Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 04:42:04 volumio volumio[20582]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 04:42:04 volumio volumio[20582]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 04:42:04 volumio volumio[20582]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 04:42:04 volumio volumio[20582]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 04:42:04 volumio volumio[20582]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 04:42:04 volumio volumio[20582]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 04:42:04 volumio volumio[20582]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 04:42:04 volumio volumio[20582]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 04:42:04 volumio go-librespot[20930]: time="2026-02-09T04:42:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:04 volumio go-librespot[20930]: time="2026-02-09T04:42:04+07:00" level=debug msg="app state loaded" Feb 09 04:42:04 volumio go-librespot[20930]: time="2026-02-09T04:42:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:04 volumio go-librespot[20930]: time="2026-02-09T04:42:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:42:04 volumio go-librespot[20930]: time="2026-02-09T04:42:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:42:04 volumio go-librespot[20930]: time="2026-02-09T04:42:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:42:04 volumio go-librespot[20930]: time="2026-02-09T04:42:04+07:00" level=info msg="zeroconf server listening on port 45095" Feb 09 04:42:05 volumio go-librespot[20930]: time="2026-02-09T04:42:05+07:00" level=debug msg="obtained new client token: AAAR7uYYB4NCd8XOtejmRn2Ot8LsAmvi3HYuLwKGK/pwVugXxWPOI36+UoiVhEX7MgA1bdoeVgbpBcHsJoHcMfEF1eWNeEtgl6ug2oHG1kOBD8TC/xzS5ckqtHsB3NZvclhu1WzHhBnqEKAmnDjjU3eZkNqJC30E7/g3FKmZNhpBEyhmrCoGCuUvOosC2g+Q/Dub1ibqCvIVcEfZhEzzYxiwHrGwBqmxlgLqr/1SzwRwCNufhSQHiuI=" Feb 09 04:42:05 volumio go-librespot[20930]: time="2026-02-09T04:42:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:05 volumio go-librespot[20930]: time="2026-02-09T04:42:05+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:05 volumio go-librespot[20930]: time="2026-02-09T04:42:05+07:00" level=debug msg="completed challenge" Feb 09 04:42:05 volumio go-librespot[20930]: time="2026-02-09T04:42:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:42:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:06 volumio volumio[20582]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 04:42:06 volumio volumio[20582]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 04:42:06 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:06 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:06 volumio volumio[20582]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 04:42:06 volumio volumio[20582]: info: MyVolumio login type: Token Feb 09 04:42:06 volumio volumio[20582]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 04:42:06 volumio volumio[20582]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 04:42:08 volumio volumio[20582]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 04:42:08 volumio volumio[20582]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 04:42:08 volumio volumio[20582]: info: Streaming services startup Feb 09 04:42:08 volumio volumio[20582]: info: Starting Streaming Daemon Feb 09 04:42:08 volumio sudo[20952]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:42:08 volumio sudo[20952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:08 volumio volumio[20582]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 04:42:08 volumio sudo[20952]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:08 volumio volumio[20582]: info: Initializing connection to go-librespot Websocket Feb 09 04:42:08 volumio volumio[20582]: error: Cannot start Volumio Streaming Daemon Feb 09 04:42:08 volumio volumio[20582]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:42:08 volumio volumio[20582]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:42:08 volumio volumio[20582]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:42:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 09 04:42:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:08 volumio go-librespot[20958]: go-librespot daemon starting... Feb 09 04:42:08 volumio go-librespot[20959]: time="2026-02-09T04:42:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:08 volumio go-librespot[20959]: time="2026-02-09T04:42:08+07:00" level=debug msg="app state loaded" Feb 09 04:42:08 volumio go-librespot[20959]: time="2026-02-09T04:42:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:09 volumio go-librespot[20959]: time="2026-02-09T04:42:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:42:09 volumio go-librespot[20959]: time="2026-02-09T04:42:09+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 09 04:42:09 volumio go-librespot[20959]: time="2026-02-09T04:42:09+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 09 04:42:09 volumio go-librespot[20959]: time="2026-02-09T04:42:09+07:00" level=info msg="zeroconf server listening on port 36861" Feb 09 04:42:09 volumio volumio[20582]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 09 04:42:09 volumio go-librespot[20959]: time="2026-02-09T04:42:09+07:00" level=debug msg="obtained new client token: AABy7yKY3bCRQAcWATWXY7B57f2f+i1sGa1vZJkae8Bp7uOjIpWcjz0BEU9gcAnr4UB8uCpg1m2Z0/8qY6ixw/KaaQEHrqN1yRX1Rx7o+oPDeRf1XEDLCKupbiC3Yl9D1QsikgT63Uofdhu+IW+dpO1NHNPrK8+Os3kPe7Ea7nqfkBAYuFM29EU4//yAR+TQOsWKfETFobrM149PpCEd5LXsy32uF/kGZkQAd245l9A56TunVh8hzQ4VGw==" Feb 09 04:42:09 volumio go-librespot[20959]: time="2026-02-09T04:42:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:09 volumio go-librespot[20959]: time="2026-02-09T04:42:09+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:09 volumio go-librespot[20959]: time="2026-02-09T04:42:09+07:00" level=debug msg="completed challenge" Feb 09 04:42:09 volumio go-librespot[20959]: time="2026-02-09T04:42:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:42:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:09 volumio volumio[20582]: info: MyVolumio token set successfully Feb 09 04:42:09 volumio volumio[20582]: info: MYVOLUMIO: Adding device Feb 09 04:42:09 volumio volumio[20582]: info: MYVOLUMIO: Evaluating Server Feb 09 04:42:10 volumio volumio[20582]: info: MyVolumio status changed Feb 09 04:42:10 volumio volumio[20582]: info: Streaming services startup Feb 09 04:42:10 volumio volumio[20582]: info: Starting Streaming Daemon Feb 09 04:42:10 volumio volumio[20582]: info: Removing browser output: myVolumio user plan is not superstar Feb 09 04:42:10 volumio volumio[20582]: info: Removing audio output: Feb 09 04:42:10 volumio volumio[20582]: info: Stoppping Tunnel 1 Feb 09 04:42:10 volumio sudo[20988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:42:10 volumio sudo[20988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:10 volumio sudo[20991]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 09 04:42:10 volumio sudo[20991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:10 volumio sudo[20988]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:10 volumio volumio[20582]: error: Cannot start Volumio Streaming Daemon Feb 09 04:42:10 volumio volumio[20582]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:42:10 volumio volumio[20582]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:42:10 volumio volumio[20582]: info: Setting Geolocation for MyVolumio to as1 Feb 09 04:42:10 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:10 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 09 04:42:10 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 09 04:42:10 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:10 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:10 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 09 04:42:10 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 09 04:42:10 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 09 04:42:10 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 09 04:42:10 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 09 04:42:10 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 09 04:42:10 volumio sudo[20991]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:10 volumio volumio[20582]: info: Remote SSH Stopped Feb 09 04:42:11 volumio volumio[20582]: info: Initializing connection to go-librespot Websocket Feb 09 04:42:11 volumio volumio[20582]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:42:11 volumio volumio[20582]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 09 04:42:11 volumio volumio[20582]: info: Updating MyVolumio device info Feb 09 04:42:11 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:11 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:11 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:12 volumio volumio[20582]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 09 04:42:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 09 04:42:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:12 volumio go-librespot[20994]: go-librespot daemon starting... Feb 09 04:42:12 volumio go-librespot[20995]: time="2026-02-09T04:42:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:12 volumio go-librespot[20995]: time="2026-02-09T04:42:12+07:00" level=debug msg="app state loaded" Feb 09 04:42:12 volumio go-librespot[20995]: time="2026-02-09T04:42:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:13 volumio go-librespot[20995]: time="2026-02-09T04:42:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:42:13 volumio go-librespot[20995]: time="2026-02-09T04:42:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:42:13 volumio go-librespot[20995]: time="2026-02-09T04:42:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:42:13 volumio go-librespot[20995]: time="2026-02-09T04:42:13+07:00" level=info msg="zeroconf server listening on port 46071" Feb 09 04:42:13 volumio go-librespot[20995]: time="2026-02-09T04:42:13+07:00" level=debug msg="obtained new client token: AAAsFytZqTwmzDDDHokXeXkMJChl7H+kGwjCpxE3WVg1PlUIDgHMi5g4flCjCuS37bcXIaY9Zwqq1SF0W5+gaXWlkayjauxLIas4d5DNkXcypwxKS6msI4mrO0wFV50QIAeoL7fVBD+1uUlmiLxPJEmCMENVqcUHf/cKnNRzldrszYGk/tUixjdvZlqIZjpDvW57/yUyHRG68MG14kMT5Hxg6x0Qewgb0UIEQLmlBDQNaZH57qNLfImBWA==" Feb 09 04:42:13 volumio go-librespot[20995]: time="2026-02-09T04:42:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:13 volumio go-librespot[20995]: time="2026-02-09T04:42:13+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:13 volumio go-librespot[20995]: time="2026-02-09T04:42:13+07:00" level=debug msg="completed challenge" Feb 09 04:42:13 volumio go-librespot[20995]: time="2026-02-09T04:42: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 09 04:42:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:14 volumio volumio[20582]: info: Initializing connection to go-librespot Websocket Feb 09 04:42:14 volumio volumio[20582]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:42:15 volumio volumio[20582]: info: MYVOLUMIO: Adding device Feb 09 04:42:15 volumio volumio[20582]: info: MYVOLUMIO: Evaluating Server Feb 09 04:42:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 09 04:42:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:17 volumio go-librespot[21035]: go-librespot daemon starting... Feb 09 04:42:17 volumio go-librespot[21036]: time="2026-02-09T04:42:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:17 volumio go-librespot[21036]: time="2026-02-09T04:42:17+07:00" level=debug msg="app state loaded" Feb 09 04:42:17 volumio go-librespot[21036]: time="2026-02-09T04:42:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:17 volumio volumio[20582]: info: Initializing connection to go-librespot Websocket Feb 09 04:42:17 volumio go-librespot[21036]: time="2026-02-09T04:42:17+07:00" level=debug msg="new websocket client" Feb 09 04:42:17 volumio volumio[20582]: info: Connection to go-librespot Websocket established Feb 09 04:42:17 volumio go-librespot[21036]: time="2026-02-09T04:42: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:42:17 volumio go-librespot[21036]: time="2026-02-09T04:42:17+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 09 04:42:17 volumio go-librespot[21036]: time="2026-02-09T04:42:17+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 09 04:42:17 volumio go-librespot[21036]: time="2026-02-09T04:42:17+07:00" level=info msg="zeroconf server listening on port 33411" Feb 09 04:42:17 volumio go-librespot[21036]: time="2026-02-09T04:42:17+07:00" level=debug msg="obtained new client token: AAAracC/GnZaVDtvwVSm4UJxh4Q6VcWR6jgS9clkoiW5TohlZcwdzWZseJ7Rq37OQwIRj6xiORD1uqcaZ+xOYwKSE/0M+8GuJrX06PzWowKcAt6aJboK/7XP6qUvYScvQCD/ggPeuwlEDJAmJbeb9JMPENrxfMda4V/V8ENHc90g5X3mboyDFe3v9ADrf5CLBQfjYjhtdiLpiV2fkF7X8XCtyCNdTfMojuhgros9fSLLeuDa0vET209TEQ==" Feb 09 04:42:17 volumio volumio[20582]: info: Setting Geolocation for MyVolumio to as1 Feb 09 04:42:17 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:17 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:17 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:17 volumio go-librespot[21036]: time="2026-02-09T04:42:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:18 volumio go-librespot[21036]: time="2026-02-09T04:42:18+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:18 volumio go-librespot[21036]: time="2026-02-09T04:42:18+07:00" level=debug msg="completed challenge" Feb 09 04:42:18 volumio go-librespot[21036]: time="2026-02-09T04:42: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 09 04:42:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:18 volumio volumio[20582]: info: Connection to go-librespot Websocket closed Feb 09 04:42:18 volumio volumio[20582]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 09 04:42:18 volumio volumio[20582]: info: Updating MyVolumio device info Feb 09 04:42:18 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:18 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:18 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:19 volumio volumio[20582]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 09 04:42:19 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:42:19 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:19 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 09 04:42:19 volumio volumio-remote-updater[643]: Test mode disabled Feb 09 04:42:19 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 09 04:42:19 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 09 04:42:19 volumio volumio[20582]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 09 04:42:20 volumio volumio[20582]: info: Getting Spotify volume Feb 09 04:42:20 volumio volumio[20582]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:42:20 volumio volumio[20582]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:42:20 volumio volumio[20582]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 04:42:20 volumio volumio[20582]: errno: -111, Feb 09 04:42:20 volumio volumio[20582]: code: 'ECONNREFUSED', Feb 09 04:42:20 volumio volumio[20582]: syscall: 'connect', Feb 09 04:42:20 volumio volumio[20582]: address: '127.0.0.1', Feb 09 04:42:20 volumio volumio[20582]: port: 9879, Feb 09 04:42:20 volumio volumio[20582]: response: undefined Feb 09 04:42:20 volumio volumio[20582]: } Feb 09 04:42:20 volumio volumio[20582]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:42:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 09 04:42:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:21 volumio go-librespot[21061]: go-librespot daemon starting... Feb 09 04:42:21 volumio go-librespot[21062]: time="2026-02-09T04:42:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:21 volumio go-librespot[21062]: time="2026-02-09T04:42:21+07:00" level=debug msg="app state loaded" Feb 09 04:42:21 volumio go-librespot[21062]: time="2026-02-09T04:42:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:21 volumio go-librespot[21062]: time="2026-02-09T04:42: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:42:21 volumio go-librespot[21062]: time="2026-02-09T04:42:21+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 09 04:42:21 volumio go-librespot[21062]: time="2026-02-09T04:42:21+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 09 04:42:21 volumio sudo[21071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 04:41' Feb 09 04:42:21 volumio sudo[21071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:21 volumio go-librespot[21062]: time="2026-02-09T04:42:21+07:00" level=info msg="zeroconf server listening on port 41399" Feb 09 04:42:22 volumio go-librespot[21062]: time="2026-02-09T04:42:22+07:00" level=debug msg="obtained new client token: AADJpsjwYDGGoqKynOaxi0ieGrzY47EcNBENl40oPHgkm6+1+xyqm1N7pYwjmHe+b2SV2cpR3L8N5YvWsSc8oBd580BQZO2gHC7+ukNa6k8N/BN/3MntWu4jUDDkQ8MiuUSOOAR0xPzxl9Ehl/PEDBaRICOP1RqTikQQpdPe3lxRwPcaZ0GKwlJE+4V8pewmmQJ94bzftXW5fhhur21s0fY39A91VyFWbHZLF6M7q660qlbeIPqrcpI=" Feb 09 04:42:22 volumio sudo[21071]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:22 volumio go-librespot[21062]: time="2026-02-09T04:42:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:22 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:22 volumio volumio-remote-updater[643]: [2026-02-09 04:42:22] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 09 04:42:22 volumio volumio-remote-updater[643]: [2026-02-09 04:42:22] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 09 04:42:22 volumio go-librespot[21062]: time="2026-02-09T04:42:22+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:22 volumio go-librespot[21062]: time="2026-02-09T04:42:22+07:00" level=debug msg="completed challenge" Feb 09 04:42:22 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 04:42:22 volumio systemd[1]: volumio.service: Consumed 58.208s CPU time. Feb 09 04:42:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 04:42:22 volumio go-librespot[21062]: time="2026-02-09T04:42:22+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 09 04:42:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 04:42:22 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8209. Feb 09 04:42:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 04:42:22 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 04:42:22 volumio systemd[1]: volumio.service: Consumed 58.208s CPU time. Feb 09 04:42:22 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 04:42:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 04:42:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 09 04:42:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:25 volumio go-librespot[21102]: go-librespot daemon starting... Feb 09 04:42:25 volumio go-librespot[21103]: time="2026-02-09T04:42:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:25 volumio go-librespot[21103]: time="2026-02-09T04:42:25+07:00" level=debug msg="app state loaded" Feb 09 04:42:25 volumio go-librespot[21103]: time="2026-02-09T04:42:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:26 volumio volumio[21087]: info: ------------------------------------------- Feb 09 04:42:26 volumio volumio[21087]: info: ----- Volumio3 ---- Feb 09 04:42:26 volumio volumio[21087]: info: ------------------------------------------- Feb 09 04:42:26 volumio volumio[21087]: info: ----- System startup ---- Feb 09 04:42:26 volumio volumio[21087]: info: ------------------------------------------- Feb 09 04:42:26 volumio go-librespot[21103]: time="2026-02-09T04:42: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-gew1.spotify.com:80]" Feb 09 04:42:26 volumio go-librespot[21103]: time="2026-02-09T04:42:26+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 09 04:42:26 volumio go-librespot[21103]: time="2026-02-09T04:42:26+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 09 04:42:26 volumio go-librespot[21103]: time="2026-02-09T04:42:26+07:00" level=info msg="zeroconf server listening on port 42001" Feb 09 04:42:26 volumio go-librespot[21103]: time="2026-02-09T04:42:26+07:00" level=debug msg="obtained new client token: AAAFixHceUrTTHvSQaspQ/Iv8b/IBh1bWHtpTIqieWvEv9ONLWwyYUO8RJSi6flfIUpgRhxtUuzGZTHyAJIXG+2T+vJzIjSdUTqIPbN4Owedchm6decy5MeHA843mmTSjSjlCz6GQvtRuJVe0CvxWqOWksaIbyTWc3RLvkKcLWpKaWP/J8RNBix3yWR9omfJ+m2zxfDS8TkttpwwaU9Q1RzWASV9FNCgIWUPNb6XeUd3j1wjikIgXV1gjA==" Feb 09 04:42:26 volumio go-librespot[21103]: time="2026-02-09T04:42:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:26 volumio go-librespot[21103]: time="2026-02-09T04:42:26+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:26 volumio go-librespot[21103]: time="2026-02-09T04:42:26+07:00" level=debug msg="completed challenge" Feb 09 04:42:26 volumio go-librespot[21103]: time="2026-02-09T04:42:26+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 09 04:42:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:27 volumio volumio-remote-updater[643]: [2026-02-09 04:42:27] [connect] Successful connection Feb 09 04:42:27 volumio volumio[21087]: info: MYVOLUMIO Environment detected Feb 09 04:42:27 volumio volumio[21087]: info: Plugin folders cleanup Feb 09 04:42:27 volumio volumio[21087]: info: Scanning into folder /volumio/app/plugins/ Feb 09 04:42:27 volumio volumio[21087]: info: Scanning category audio_interface Feb 09 04:42:27 volumio volumio[21087]: info: Scanning category miscellanea Feb 09 04:42:27 volumio volumio[21087]: info: Scanning category music_service Feb 09 04:42:27 volumio volumio[21087]: info: Scanning category plugins.json Feb 09 04:42:27 volumio volumio[21087]: info: Scanning category system_controller Feb 09 04:42:27 volumio volumio[21087]: info: Scanning category user_interface Feb 09 04:42:27 volumio volumio[21087]: info: Scanning into folder /data/plugins/ Feb 09 04:42:27 volumio volumio[21087]: info: Scanning category music_service Feb 09 04:42:27 volumio volumio[21087]: info: Plugin folders cleanup completed Feb 09 04:42:27 volumio volumio[21087]: info: ------------------------------------------- Feb 09 04:42:27 volumio volumio[21087]: info: ----- Core plugins startup ---- Feb 09 04:42:27 volumio volumio[21087]: info: ------------------------------------------- Feb 09 04:42:27 volumio volumio[21087]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 04:42:27 volumio volumio[21087]: info: Adding plugin upnp to MyMusic Plugins Feb 09 04:42:27 volumio volumio[21087]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 04:42:27 volumio volumio[21087]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 04:42:27 volumio volumio[21087]: info: Loading plugins from folder /data/plugins/ Feb 09 04:42:27 volumio volumio[21087]: info: Loading plugin "system"... Feb 09 04:42:27 volumio volumio[21087]: info: Loading plugin "appearance"... Feb 09 04:42:29 volumio volumio[21087]: info: Loading plugin "network"... Feb 09 04:42:29 volumio volumio[21087]: info: Refreshing Cached IP Addresses Feb 09 04:42:29 volumio sudo[21126]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:42:29 volumio sudo[21126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:29 volumio sudo[21128]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:42:29 volumio sudo[21128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:29 volumio volumio[21087]: info: Loading plugin "services"... Feb 09 04:42:29 volumio sudo[21126]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:29 volumio volumio[21087]: info: Loading plugin "alsa_controller"... Feb 09 04:42:29 volumio sudo[21128]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 09 04:42:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:29 volumio sudo[21139]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 04:42:29 volumio sudo[21139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:29 volumio go-librespot[21151]: go-librespot daemon starting... Feb 09 04:42:29 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:42:29 volumio go-librespot[21160]: time="2026-02-09T04:42:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:29 volumio go-librespot[21160]: time="2026-02-09T04:42:29+07:00" level=debug msg="app state loaded" Feb 09 04:42:29 volumio volumio[21087]: info: Loading plugin "wizard"... Feb 09 04:42:29 volumio go-librespot[21160]: time="2026-02-09T04:42:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:29 volumio volumio[21087]: info: Loading plugin "networkfs"... Feb 09 04:42:30 volumio volumio[21087]: info: Starting Udev Watcher for removable devices Feb 09 04:42:30 volumio volumio[21087]: info: Ignoring mount for partition: boot Feb 09 04:42:30 volumio volumio[21087]: info: Ignoring mount for partition: volumio Feb 09 04:42:30 volumio volumio[21087]: info: Ignoring mount for partition: volumio_data Feb 09 04:42:30 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:42:30 volumio volumio[21087]: info: Loading plugin "volumio_command_line_client"... Feb 09 04:42:30 volumio volumio[21087]: info: Loading plugin "upnp"... Feb 09 04:42:30 volumio volumio[21087]: info: [1770586950123] Starting Upmpd Daemon Feb 09 04:42:30 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:42:30 volumio volumio[21087]: info: Loading plugin "my_music"... Feb 09 04:42:30 volumio volumio[21087]: info: Loading plugin "mpd"... Feb 09 04:42:30 volumio go-librespot[21160]: time="2026-02-09T04:42: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:42:30 volumio go-librespot[21160]: time="2026-02-09T04:42:30+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 09 04:42:30 volumio go-librespot[21160]: time="2026-02-09T04:42:30+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 09 04:42:30 volumio go-librespot[21160]: time="2026-02-09T04:42:30+07:00" level=info msg="zeroconf server listening on port 33023" Feb 09 04:42:30 volumio go-librespot[21160]: time="2026-02-09T04:42:30+07:00" level=debug msg="obtained new client token: AADSZQ6e4M0fYmQAQGOyr4Au5XABQgSgkv4Ppk5isUt996OSb+skhTyAZCBS/+ULWnd9w8pz3uK3+UpgbSfK8Ifx9r50LHANIQsuCGd49Hv3DR1I4aC6GbgWzePixFvYHBk/cpz8hnaGR/Vb01DPJ0thWWiE4Bp4NpHzVs+mxnL2CtrTlvxZomqWmywqBKPNaH4VBGLXvkqR65MqwzNS16DetVXA+LnxnGQkg8bmEc4UBygOqqX5KyB1hw==" Feb 09 04:42:30 volumio volumio[21087]: info: Loading plugin "upnp_browser"... Feb 09 04:42:30 volumio go-librespot[21160]: time="2026-02-09T04:42:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:31 volumio go-librespot[21160]: time="2026-02-09T04:42:31+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:31 volumio go-librespot[21160]: time="2026-02-09T04:42:31+07:00" level=debug msg="completed challenge" Feb 09 04:42:31 volumio go-librespot[21160]: time="2026-02-09T04:42:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:42:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:32 volumio sudo[21139]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:33 volumio volumio[21087]: info: Starting UPNP Browser Feb 09 04:42:33 volumio volumio[21087]: info: Loading plugin "alarm-clock"... Feb 09 04:42:34 volumio volumio[21087]: info: Loading plugin "airplay_emulation"... Feb 09 04:42:34 volumio volumio[21087]: info: Starting Shairport Sync Feb 09 04:42:34 volumio volumio[21087]: info: Loading plugin "last_100"... Feb 09 04:42:34 volumio volumio[21087]: info: Loading plugin "webradio"... Feb 09 04:42:34 volumio volumio[21087]: info: Loading plugin "i2s_dacs"... Feb 09 04:42:34 volumio volumio[21087]: info: Loading plugin "volumiodiscovery"... Feb 09 04:42:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 09 04:42:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:34 volumio volumio[21087]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:42:34 volumio volumio[21087]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:42:34 volumio volumio[21087]: *** WARNING *** For more information see Feb 09 04:42:34 volumio volumio[21087]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:42:34 volumio volumio[21087]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:42:34 volumio volumio[21087]: *** WARNING *** For more information see Feb 09 04:42:34 volumio node[21087]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:42:34 volumio node[21087]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:42:34 volumio node[21087]: *** WARNING *** For more information see Feb 09 04:42:34 volumio node[21087]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:42:34 volumio node[21087]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:42:34 volumio node[21087]: *** WARNING *** For more information see Feb 09 04:42:34 volumio volumio[21087]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 04:42:34 volumio volumio[21087]: info: Discovery: Started advertising with name: Volumio Feb 09 04:42:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:34 volumio go-librespot[21169]: go-librespot daemon starting... Feb 09 04:42:34 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:42:34 volumio volumio[21087]: info: Loading plugin "spop"... Feb 09 04:42:34 volumio go-librespot[21172]: time="2026-02-09T04:42:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:34 volumio go-librespot[21172]: time="2026-02-09T04:42:34+07:00" level=debug msg="app state loaded" Feb 09 04:42:34 volumio go-librespot[21172]: time="2026-02-09T04:42:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:34 volumio go-librespot[21172]: time="2026-02-09T04:42:34+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 09 04:42:34 volumio go-librespot[21172]: time="2026-02-09T04:42:34+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 09 04:42:34 volumio go-librespot[21172]: time="2026-02-09T04:42:34+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 09 04:42:34 volumio go-librespot[21172]: time="2026-02-09T04:42:34+07:00" level=info msg="zeroconf server listening on port 43329" Feb 09 04:42:35 volumio go-librespot[21172]: time="2026-02-09T04:42:35+07:00" level=debug msg="obtained new client token: AAAgu51cJ7Wwef3WDuy9JM6eNLb4BTp2CU/JAqw196XMyjM1UNnNfSMrQgwzxCJDKKcINmfavwSY9PlgcCA79d5ZNtvx9h0Zzhj5KZIS0vacewINzD0G650BNjtjeTsB9wf7Ev+HpnjWPWWl/eL6vzlTv1GzN4FIFrGL6zUviRPdb1EnaKAQc06KEZrINttR8G1Bqz5NgkLFQUEAKl5Z1PtzA6zv1stKUM1eLi+fG7BtGj8k1d/JV/4=" Feb 09 04:42:35 volumio go-librespot[21172]: time="2026-02-09T04:42:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:35 volumio go-librespot[21172]: time="2026-02-09T04:42:35+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:35 volumio go-librespot[21172]: time="2026-02-09T04:42:35+07:00" level=debug msg="completed challenge" Feb 09 04:42:35 volumio go-librespot[21172]: time="2026-02-09T04:42:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:42:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:36 volumio volumio[21087]: info: Loading plugin "ytcr"... Feb 09 04:42:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 09 04:42:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:38 volumio go-librespot[21180]: go-librespot daemon starting... Feb 09 04:42:38 volumio go-librespot[21181]: time="2026-02-09T04:42:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:38 volumio go-librespot[21181]: time="2026-02-09T04:42:38+07:00" level=debug msg="app state loaded" Feb 09 04:42:38 volumio go-librespot[21181]: time="2026-02-09T04:42:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:39 volumio volumio[21087]: info: Loading plugin "ytmusic"... Feb 09 04:42:39 volumio go-librespot[21181]: time="2026-02-09T04:42:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:42:39 volumio go-librespot[21181]: time="2026-02-09T04:42:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:42:39 volumio go-librespot[21181]: time="2026-02-09T04:42:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:42:39 volumio go-librespot[21181]: time="2026-02-09T04:42:39+07:00" level=info msg="zeroconf server listening on port 43991" Feb 09 04:42:39 volumio go-librespot[21181]: time="2026-02-09T04:42:39+07:00" level=debug msg="obtained new client token: AAAAuF6r38+AndY5jyKMbooU3gsDNjG0MoCCQP1FSo5bhmxCIm4YUM+JdPE/HGfvtuRX3siuQ5I1anptEv+jSgA80ZF6i1eyRNLCZRC682NT+CuYGwQ1J/y9aOeC4EsmKvOKSxbC9qNcAXlzhM5bY7LOeW3yMhZTWcCLgqSYYwGaRzEfELBmECghdyqIYF5q+byuDdyrffF1vF0Udg5L2KTjtpCIUa7BsFTYSlpfVdP2ZUgC3Ez5uSnSHg==" Feb 09 04:42:39 volumio go-librespot[21181]: time="2026-02-09T04:42:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:39 volumio volumio-remote-updater[643]: [2026-02-09 04:42:39] [connect] Successful connection Feb 09 04:42:39 volumio go-librespot[21181]: time="2026-02-09T04:42:39+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:39 volumio go-librespot[21181]: time="2026-02-09T04:42:39+07:00" level=debug msg="completed challenge" Feb 09 04:42:39 volumio go-librespot[21181]: time="2026-02-09T04:42:39+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 09 04:42:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:40 volumio volumio[21087]: info: Loading plugin "outputs"... Feb 09 04:42:40 volumio volumio[21087]: info: Loading plugin "albumart"... Feb 09 04:42:40 volumio volumio[21087]: info: Plugin example_plugin is not enabled Feb 09 04:42:40 volumio volumio[21087]: info: Loading plugin "inputs"... Feb 09 04:42:40 volumio volumio[21087]: info: Loading plugin "updater_comm"... Feb 09 04:42:40 volumio volumio[21087]: info: Plugin mpdemulation is not enabled Feb 09 04:42:40 volumio volumio[21087]: info: Loading plugin "rest_api"... Feb 09 04:42:40 volumio volumio[21087]: info: Loading plugin "websocket"... Feb 09 04:42:40 volumio volumio[21087]: info: Starting Socket.io Server version 1.7.4 Feb 09 04:42:40 volumio volumio[21087]: info: Loading plugin "RoonBridge"... Feb 09 04:42:40 volumio volumio[21087]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 04:42:40 volumio volumio[21087]: info: Loading i18n strings for locale en Feb 09 04:42:41 volumio volumio[21087]: Updating browse sources language Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:42:41 volumio volumio[21202]: Forking 3 albumart workers Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::initPlayerControls Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:42:41 volumio volumio[21087]: Express server listening on port 3000 Feb 09 04:42:41 volumio volumio[21087]: [Metrics] WebUI: 16s 172.26ms Feb 09 04:42:41 volumio volumio[21087]: info: CoreStateMachine::resetVolumioState Feb 09 04:42:41 volumio volumio[21087]: info: CoreStateMachine::getcurrentVolume Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:42:41 volumio sudo[21248]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:42:41 volumio sudo[21248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:41 volumio sudo[21250]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:42:41 volumio sudo[21250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:41 volumio sudo[21248]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:41 volumio sudo[21250]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:41 volumio volumio[21087]: info: Volumio Network Manager: Network status updated: 1 Feb 09 04:42:41 volumio volumio[21087]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:42:41 volumio volumio[21087]: info: CoreStateMachine::pushState Feb 09 04:42:41 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::volumioPushState Feb 09 04:42:41 volumio volumio[21087]: info: CoreStateMachine::updateTrackBlock Feb 09 04:42:41 volumio volumio[21087]: info: CorePlayQueue::getTrackBlock Feb 09 04:42:41 volumio volumio[21087]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:42:41 volumio volumio-remote-updater[643]: [2026-02-09 04:42:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770586959 101 Feb 09 04:42:42 volumio volumio[21087]: 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 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:42 volumio volumio[21087]: info: Reloading queue from file Feb 09 04:42:42 volumio volumio[21087]: info: CoreStateMachine::setRepeat null single undefined Feb 09 04:42:42 volumio volumio[21087]: info: CoreStateMachine::pushState Feb 09 04:42:42 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::volumioPushState Feb 09 04:42:42 volumio volumio[21087]: info: CoreStateMachine::setRandom null Feb 09 04:42:42 volumio volumio[21087]: info: CoreStateMachine::pushState Feb 09 04:42:42 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::volumioPushState Feb 09 04:42:42 volumio volumio[21087]: info: Setting Device type: Raspberry PI Feb 09 04:42:42 volumio volumio[21087]: info: Completed loading Core Plugins Feb 09 04:42:42 volumio volumio[21087]: info: Preparing to generate the ALSA configuration file Feb 09 04:42:42 volumio volumio[21087]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:42:42 volumio volumio[21087]: info: CoreStateMachine::pushState Feb 09 04:42:42 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::volumioPushState Feb 09 04:42:42 volumio volumio[21087]: info: Asound.conf file unchanged, so no further update is needed Feb 09 04:42:42 volumio volumio[21087]: info: Output device has changed, restarting MPD Feb 09 04:42:42 volumio volumio[21087]: info: Output device has changed, restarting Shairport Sync Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:42 volumio sudo[21264]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 04:42:42 volumio sudo[21264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:42 volumio volumio[21087]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:42:42 volumio sudo[21266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:42:42 volumio sudo[21266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:42 volumio volumio[21087]: info: ___________ START PLUGINS ___________ Feb 09 04:42:42 volumio sudo[21266]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:42 volumio volumio[21087]: info: ControllerMpd::onStart: Initializing MPD Feb 09 04:42:42 volumio volumio[21087]: info: Creating MPD Configuration file Feb 09 04:42:42 volumio sudo[21268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:42:42 volumio sudo[21268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:42 volumio sudo[21264]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:42:42 volumio sudo[21277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:42:42 volumio sudo[21277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:42:42 volumio volumio[21087]: info: [1770586962650] CoreMusicLibrary::Adding element Media Servers Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:42:42 volumio sudo[21277]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:42 volumio volumio[21087]: info: UPNP Browser: Client initialized successfully Feb 09 04:42:42 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 04:42:42 volumio sudo[21279]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:42:42 volumio sudo[21279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:42 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 04:42:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 04:42:42 volumio systemd[1]: mpd.service: Consumed 7.197s CPU time. Feb 09 04:42:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 04:42:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 04:42:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 04:42:42 volumio volumio[21087]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:42 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 04:42:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 04:42:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 09 04:42:43 volumio volumio[21087]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:42:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:43 volumio volumio[21087]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:42:43 volumio volumio[21087]: info: [1770586963048] CoreMusicLibrary::Adding element Last_100 Feb 09 04:42:43 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:42:43 volumio go-librespot[21292]: go-librespot daemon starting... Feb 09 04:42:43 volumio volumio[21087]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:42:43 volumio volumio[21087]: info: [1770586963086] CoreMusicLibrary::Adding element Webradio Feb 09 04:42:43 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:42:43 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:42:43 volumio volumio[21087]: info: Initializing BBC Radios Feb 09 04:42:43 volumio go-librespot[21293]: time="2026-02-09T04:42:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:43 volumio go-librespot[21293]: time="2026-02-09T04:42:43+07:00" level=debug msg="app state loaded" Feb 09 04:42:43 volumio go-librespot[21293]: time="2026-02-09T04:42:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:43 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:42:43 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:43 volumio volumio[21087]: info: Creating Spotify config file Feb 09 04:42:43 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:43 volumio sudo[21291]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 04:42:43 volumio sudo[21291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 04:42:43 volumio sudo[21291]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:43 volumio go-librespot[21293]: time="2026-02-09T04:42:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:42:43 volumio go-librespot[21293]: time="2026-02-09T04:42:43+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 09 04:42:43 volumio go-librespot[21293]: time="2026-02-09T04:42:43+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 09 04:42:43 volumio go-librespot[21293]: time="2026-02-09T04:42:43+07:00" level=info msg="zeroconf server listening on port 39385" Feb 09 04:42:44 volumio go-librespot[21293]: time="2026-02-09T04:42:44+07:00" level=debug msg="obtained new client token: AACD85JYodOoKTmiVn1kS2yb36RctWOxJKFtIu2MywhrcMCwtfYoLVgc6375FGSoTdtPXCjkIygBfwpvaiaPmIrW7SYIo3Gj6SiRSaD/Uua/vh8ku4UgaA4ivqURO4+kjkhjNuOrGpalv1aSDbMI/tFIOCbwY+MELhyXwYhR8v9Tno/d7WUMvJn1ZZ9wd/Rg6qGaxP2P6SqXjvMTVyNg5bgDlDjLqk9Mgo2AFdtGFNqU7tO8paIDUE0=" Feb 09 04:42:44 volumio go-librespot[21293]: time="2026-02-09T04:42:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:44 volumio go-librespot[21293]: time="2026-02-09T04:42:44+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:44 volumio go-librespot[21293]: time="2026-02-09T04:42:44+07:00" level=debug msg="completed challenge" Feb 09 04:42:44 volumio volumio[21087]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:42:44 volumio volumio[21087]: info: [1770586964436] CoreMusicLibrary::Adding element YouTube Music Feb 09 04:42:44 volumio go-librespot[21293]: time="2026-02-09T04:42:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:42:44 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:42:44 volumio volumio[21087]: Cannot find translation for source YouTube Music Feb 09 04:42:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:44 volumio volumio[21087]: info: Volumio Calling Home Feb 09 04:42:44 volumio sudo[21318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 04:42:44 volumio sudo[21318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:44 volumio sudo[21318]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:44 volumio volumio[21213]: Starting albumart workers Feb 09 04:42:44 volumio volumio[21215]: Starting albumart workers Feb 09 04:42:45 volumio volumio[21214]: Starting albumart workers Feb 09 04:42:45 volumio volumio[21087]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:42:45 volumio volumio[21087]: info: Discovery: Found device Volumio Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::volumioGetState Feb 09 04:42:45 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:42:45 volumio volumio[21087]: info: MPD Permissions set Feb 09 04:42:45 volumio volumio[21087]: info: MPD Permissions set Feb 09 04:42:45 volumio volumio[21087]: info: Upmpdcli Daemon Started Feb 09 04:42:45 volumio volumio[21087]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:42:45 volumio volumio[21087]: info: Discovery: Found device Volumio Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::volumioGetState Feb 09 04:42:45 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:42:45 volumio volumio[21087]: info: Volumio called home Feb 09 04:42:45 volumio volumio[21087]: info: Spotify config file written Feb 09 04:42:45 volumio volumio[21087]: 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 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio sudo[21324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio sudo[21324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:45 volumio go-librespot[21331]: go-librespot daemon starting... Feb 09 04:42:45 volumio sudo[21324]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:46 volumio go-librespot[21334]: time="2026-02-09T04:42:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:46 volumio go-librespot[21334]: time="2026-02-09T04:42:46+07:00" level=debug msg="app state loaded" Feb 09 04:42:46 volumio go-librespot[21334]: time="2026-02-09T04:42:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:46 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:42:46 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:42:46 volumio volumio[21087]: info: No need to fix Spotify hosts Feb 09 04:42:46 volumio go-librespot[21334]: time="2026-02-09T04:42: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:42:46 volumio go-librespot[21334]: time="2026-02-09T04:42:46+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 09 04:42:46 volumio go-librespot[21334]: time="2026-02-09T04:42:46+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 09 04:42:46 volumio go-librespot[21334]: time="2026-02-09T04:42:46+07:00" level=info msg="zeroconf server listening on port 38183" Feb 09 04:42:47 volumio go-librespot[21334]: time="2026-02-09T04:42:47+07:00" level=debug msg="obtained new client token: AAAW5ekZigMP18GRiKKnuhUwr9q1Rha92c7n9ApMYX052T+Pc57GqfW50kprSIB3yHMk/FPoXud9QK5bgpUvvNY2XTXDIQCRTMvtQDto+mAlueoY7s0unOlCDFiLXFiF3VIpmPnSPJHk825J5Eoyd+xSK8BfBWRmKXPfsv2a3kzjmsGrpGqCJFsxFvsRnxdqkzvJOs+zzykPK/iEwdxMjVENLqT3lkPL7eKg+4w2e1U75pA7o8c9nc82aw==" Feb 09 04:42:47 volumio go-librespot[21334]: time="2026-02-09T04:42:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:47 volumio go-librespot[21334]: time="2026-02-09T04:42:47+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:47 volumio go-librespot[21334]: time="2026-02-09T04:42:47+07:00" level=debug msg="completed challenge" Feb 09 04:42:47 volumio go-librespot[21334]: time="2026-02-09T04:42:47+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 09 04:42:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:47 volumio volumio[21087]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:42:47 volumio volumio[21087]: SPOTIFY: BQA7OFv_vW1yRwJlcK20d-fzXt8_B5Gzp1xVFKqmUUjfkyYnaGtTluLtto8WE47KBpBLKBT6e6uUEpEqx79XtfO0ZeJcLoezalV04C6nrjOfkXWAT8mBigXIzsUjXluH3aoGcts6aFdr17DL3ZDSzUtaTXd_KqwP1NC6vCYZfiJ-_kJWaL89TTSQPcnKfhkHPF97U-14FO6Dgt_7nUdw6n6rZcX0wQ3oD9-XJ7q41G4tH7GZNgO0rdaUrwVS38zRNHKPqy0deZZHp95UnameXQt-a1K5ZpBfnzpj0MU2eSnaGjiJ9VKW7BBV Feb 09 04:42:47 volumio volumio[21087]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:42:47 volumio volumio[21087]: info: New Spotify access token = BQA7OFv_vW1yRwJlcK20d-fzXt8_B5Gzp1xVFKqmUUjfkyYnaGtTluLtto8WE47KBpBLKBT6e6uUEpEqx79XtfO0ZeJcLoezalV04C6nrjOfkXWAT8mBigXIzsUjXluH3aoGcts6aFdr17DL3ZDSzUtaTXd_KqwP1NC6vCYZfiJ-_kJWaL89TTSQPcnKfhkHPF97U-14FO6Dgt_7nUdw6n6rZcX0wQ3oD9-XJ7q41G4tH7GZNgO0rdaUrwVS38zRNHKPqy0deZZHp95UnameXQt-a1K5ZpBfnzpj0MU2eSnaGjiJ9VKW7BBV Feb 09 04:42:47 volumio volumio[21087]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 04:42:47 volumio volumio[21087]: info: Starting Shairport Sync Feb 09 04:42:47 volumio volumio[21087]: info: Starting Shairport Sync Feb 09 04:42:47 volumio volumio[21087]: info: Starting Shairport Sync Feb 09 04:42:47 volumio sudo[21364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:42:47 volumio sudo[21364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:47 volumio sudo[21366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:42:47 volumio sudo[21366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:47 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 04:42:47 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 04:42:47 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:42:47 volumio systemd[1]: shairport-sync.service: Consumed 2.381s CPU time. Feb 09 04:42:47 volumio sudo[21368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:42:47 volumio sudo[21368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:42:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:42:48 volumio sudo[21364]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 04:42:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 04:42:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:42:48 volumio volumio[21087]: info: CoreCommandRouter::volumioGetState Feb 09 04:42:48 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:42:48 volumio volumio[21087]: info: Shairport-Sync Started Feb 09 04:42:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:42:48 volumio volumio[21087]: Error adding Membership: Error: addMembership EINVAL Feb 09 04:42:48 volumio sudo[21368]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:48 volumio sudo[21366]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:48 volumio volumio[21087]: info: Shairport-Sync Started Feb 09 04:42:48 volumio volumio[21087]: info: Shairport-Sync Started Feb 09 04:42:48 volumio volumio[21087]: 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 09 04:42:48 volumio volumio[21087]: info: Spotify Successfully logged in Feb 09 04:42:48 volumio volumio[21087]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:42:48 volumio volumio[21087]: info: [1770586968415] CoreMusicLibrary::Adding element Spotify Feb 09 04:42:48 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:42:48 volumio volumio[21087]: Cannot find translation for source YouTube Music Feb 09 04:42:48 volumio volumio[21087]: Cannot find translation for source Spotify Feb 09 04:42:48 volumio volumio[21087]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 04:42:48 volumio volumio[21087]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:42:49 volumio volumio[21087]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:42:49 volumio volumio[21087]: info: CoreCommandRouter::volumioGetState Feb 09 04:42:49 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:42:49 volumio volumio[21087]: info: CoreStateMachine::pushState Feb 09 04:42:49 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:42:49 volumio volumio[21087]: info: CoreCommandRouter::volumioPushState Feb 09 04:42:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 09 04:42:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:50 volumio go-librespot[21404]: go-librespot daemon starting... Feb 09 04:42:50 volumio go-librespot[21405]: time="2026-02-09T04:42:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:50 volumio go-librespot[21405]: time="2026-02-09T04:42:50+07:00" level=debug msg="app state loaded" Feb 09 04:42:50 volumio go-librespot[21405]: time="2026-02-09T04:42:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:50 volumio volumio[21087]: info: go-librespot daemon successfully initialized Feb 09 04:42:50 volumio mpd[21315]: 2026-02-09T04:42:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 04:42:50 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 04:42:50 volumio sudo[21279]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:50 volumio sudo[21268]: pam_unix(sudo:session): session closed for user root Feb 09 04:42:50 volumio volumio[21087]: error: MPD error: The expression evaluated to a falsy value: Feb 09 04:42:50 volumio volumio[21087]: assert.ok(self.idling) Feb 09 04:42:50 volumio volumio[21087]: error: The expression evaluated to a falsy value: Feb 09 04:42:50 volumio volumio[21087]: assert.ok(self.idling) Feb 09 04:42:50 volumio volumio[21087]: error: updateQueue error: null Feb 09 04:42:50 volumio volumio[21087]: info: MPD running with PID21315 Feb 09 04:42:50 volumio volumio[21087]: ,establishing connection Feb 09 04:42:50 volumio volumio[21087]: info: Completed starting Core Plugins Feb 09 04:42:50 volumio volumio[21087]: info: ------------------------------------------- Feb 09 04:42:50 volumio volumio[21087]: info: ----- MyVolumio plugins startup ---- Feb 09 04:42:50 volumio volumio[21087]: info: ------------------------------------------- Feb 09 04:42:50 volumio volumio[21087]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 04:42:50 volumio volumio[21087]: error: updateQueue error: null Feb 09 04:42:50 volumio go-librespot[21405]: time="2026-02-09T04:42: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 09 04:42:50 volumio go-librespot[21405]: time="2026-02-09T04:42: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 09 04:42:50 volumio go-librespot[21405]: time="2026-02-09T04:42: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 09 04:42:50 volumio go-librespot[21405]: time="2026-02-09T04:42:50+07:00" level=info msg="zeroconf server listening on port 41487" Feb 09 04:42:51 volumio go-librespot[21405]: time="2026-02-09T04:42:51+07:00" level=debug msg="obtained new client token: AAA71IUSMTdBgK5nNGvV5kstXWUQ9z7mCqnKDGrFN0I15VBkOkHr4rzyIOQDV2+lqFd+PQlVWxDI1GABWWSwNXqsCZ2jbaoS5lQZm20pv2d0f3k/F0HsoL5nzchSWci9eEBx46RLWlzOpTMnd6C+qX4FvSC3fq5Jy6SEYj2lWeWnYLTf4Fqwg9ZrQ3aiLiiGYi+euRQlkUmILXghYfenIfffafjSx00tNGNBlNJdvoLb0OgBBFICDts=" Feb 09 04:42:51 volumio go-librespot[21405]: time="2026-02-09T04:42:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:51 volumio go-librespot[21405]: time="2026-02-09T04:42:51+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:51 volumio go-librespot[21405]: time="2026-02-09T04:42:51+07:00" level=debug msg="completed challenge" Feb 09 04:42:51 volumio go-librespot[21405]: time="2026-02-09T04:42:51+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 09 04:42:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:53 volumio volumio[21087]: info: Initializing connection to go-librespot Websocket Feb 09 04:42:53 volumio volumio[21087]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:42:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 09 04:42:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:54 volumio go-librespot[21416]: go-librespot daemon starting... Feb 09 04:42:54 volumio go-librespot[21417]: time="2026-02-09T04:42:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:54 volumio go-librespot[21417]: time="2026-02-09T04:42:54+07:00" level=debug msg="app state loaded" Feb 09 04:42:54 volumio go-librespot[21417]: time="2026-02-09T04:42:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:55 volumio go-librespot[21417]: time="2026-02-09T04:42: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:42:55 volumio go-librespot[21417]: time="2026-02-09T04:42:55+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 09 04:42:55 volumio go-librespot[21417]: time="2026-02-09T04:42:55+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 09 04:42:55 volumio go-librespot[21417]: time="2026-02-09T04:42:55+07:00" level=info msg="zeroconf server listening on port 35645" Feb 09 04:42:55 volumio go-librespot[21417]: time="2026-02-09T04:42:55+07:00" level=debug msg="obtained new client token: AADrHxBYCcpcTelB97u20tSbSkuMgGWe7aMe8oDGbGjozt3Us9yn/hCWnRhiW7HNGtONlDoLQom7D0iHtATY7WfZha49OJkn8WNF4eNw6kBL/gjxqRrVU48+gVZ6fgvlilvkMgdkDyFcxGv6LZyoySHX/t6B7NKI7fH8JUKSaQF87KPOgRacV6stITgftN27imU6tE61jGnpgIJSt+2M38mloPcv8Cb0d96i6ihSW/kBo5LEHHKbgIIjNg==" Feb 09 04:42:55 volumio go-librespot[21417]: time="2026-02-09T04:42:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:55 volumio go-librespot[21417]: time="2026-02-09T04:42:55+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:55 volumio go-librespot[21417]: time="2026-02-09T04:42:55+07:00" level=debug msg="completed challenge" Feb 09 04:42:55 volumio volumio[21087]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 04:42:55 volumio go-librespot[21417]: time="2026-02-09T04:42: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 09 04:42:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:42:56 volumio volumio[21087]: info: Initializing connection to go-librespot Websocket Feb 09 04:42:56 volumio volumio[21087]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:42:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 09 04:42:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:42:58 volumio go-librespot[21424]: go-librespot daemon starting... Feb 09 04:42:58 volumio go-librespot[21425]: time="2026-02-09T04:42:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:42:58 volumio go-librespot[21425]: time="2026-02-09T04:42:58+07:00" level=debug msg="app state loaded" Feb 09 04:42:58 volumio go-librespot[21425]: time="2026-02-09T04:42:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:42:59 volumio go-librespot[21425]: time="2026-02-09T04:42: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 09 04:42:59 volumio go-librespot[21425]: time="2026-02-09T04:42: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 09 04:42:59 volumio go-librespot[21425]: time="2026-02-09T04:42: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 09 04:42:59 volumio go-librespot[21425]: time="2026-02-09T04:42:59+07:00" level=info msg="zeroconf server listening on port 46825" Feb 09 04:42:59 volumio volumio[21087]: info: Initializing connection to go-librespot Websocket Feb 09 04:42:59 volumio go-librespot[21425]: time="2026-02-09T04:42:59+07:00" level=debug msg="new websocket client" Feb 09 04:42:59 volumio volumio[21087]: info: Connection to go-librespot Websocket established Feb 09 04:42:59 volumio go-librespot[21425]: time="2026-02-09T04:42:59+07:00" level=debug msg="obtained new client token: AADg1dRlufDrM4L4XAxfpX0O6pxSI7UzNkfnavCFxLRQuQ2nLG8h4rdEiDz1BttxDXKeDj1wgD05XEOwB5cBOKoZa0i5KqmNkIdJwwaPL7ecnoahHsUmJe8zUrVC14NPgHzFESNe/9E4tWO4nr+FG0u9hpV2NMRICPYqOcP0W4ZOS7D1TOfklsqiyXJGQCBh4/R+q+QZAIwu2JfYelxWSkeaIKPMWI4TNhlbi6QtHoiAbsKc6F2XRW66rQ==" Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 04:42:59 volumio volumio[21087]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 04:42:59 volumio volumio[21087]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 04:42:59 volumio volumio[21087]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 04:42:59 volumio volumio[21087]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 04:42:59 volumio volumio[21087]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 04:42:59 volumio volumio[21087]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 04:42:59 volumio volumio[21087]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 04:42:59 volumio volumio[21087]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 04:42:59 volumio go-librespot[21425]: time="2026-02-09T04:42:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:42:59 volumio go-librespot[21425]: time="2026-02-09T04:42:59+07:00" level=debug msg="completed keyexchange" Feb 09 04:42:59 volumio go-librespot[21425]: time="2026-02-09T04:42:59+07:00" level=debug msg="completed challenge" Feb 09 04:42:59 volumio go-librespot[21425]: time="2026-02-09T04:42:59+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 09 04:42:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:42:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:01 volumio volumio[21087]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 04:43:01 volumio volumio[21087]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 04:43:01 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:01 volumio volumio[21087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:01 volumio volumio[21087]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 04:43:01 volumio volumio[21087]: info: MyVolumio login type: Token Feb 09 04:43:01 volumio volumio[21087]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 04:43:01 volumio volumio[21087]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 04:43:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 09 04:43:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:03 volumio go-librespot[21448]: go-librespot daemon starting... Feb 09 04:43:03 volumio go-librespot[21449]: time="2026-02-09T04:43:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:03 volumio go-librespot[21449]: time="2026-02-09T04:43:03+07:00" level=debug msg="app state loaded" Feb 09 04:43:03 volumio go-librespot[21449]: time="2026-02-09T04:43:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:03 volumio volumio[21087]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 04:43:03 volumio volumio[21087]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 04:43:03 volumio volumio[21087]: info: Streaming services startup Feb 09 04:43:03 volumio volumio[21087]: info: Starting Streaming Daemon Feb 09 04:43:03 volumio sudo[21457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:43:03 volumio volumio[21087]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 04:43:03 volumio sudo[21457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:03 volumio sudo[21457]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:03 volumio volumio[21087]: info: Getting Spotify volume Feb 09 04:43:03 volumio volumio[21087]: info: Connection to go-librespot Websocket closed Feb 09 04:43:03 volumio volumio[21087]: error: Cannot start Volumio Streaming Daemon Feb 09 04:43:03 volumio volumio[21087]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:43:03 volumio volumio[21087]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:43:03 volumio volumio[21087]: 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 09 04:43:03 volumio go-librespot[21449]: time="2026-02-09T04:43: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:43:03 volumio go-librespot[21449]: time="2026-02-09T04:43:03+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 09 04:43:03 volumio go-librespot[21449]: time="2026-02-09T04:43:03+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 09 04:43:03 volumio go-librespot[21449]: time="2026-02-09T04:43:03+07:00" level=info msg="zeroconf server listening on port 43499" Feb 09 04:43:03 volumio volumio[21087]: info: CoreCommandRouter::volumioGetState Feb 09 04:43:03 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:03 volumio volumio[21087]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 09 04:43:03 volumio volumio[21087]: SPOTIFY: SPOTIFY VOLUME undefined Feb 09 04:43:03 volumio volumio[21087]: SPOTIFY: VOLUMIO VOLUME 100 Feb 09 04:43:03 volumio volumio[21087]: info: Aligning Spotify Volume to Volumio Volume Feb 09 04:43:03 volumio volumio[21087]: info: CoreCommandRouter::volumioGetState Feb 09 04:43:03 volumio volumio[21087]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:03 volumio volumio[21087]: info: Setting Spotify Volume from Volumio: 100 Feb 09 04:43:03 volumio go-librespot[21449]: time="2026-02-09T04:43:03+07:00" level=debug msg="obtained new client token: AAA0fM+V+f4WQseg6XBKB5cc4ZLEpbagFVXSW8NywiU0sV+TES3PRKeJwdHXP2a89Q8oMBOFkRYY7QJNZSxWh5MMAEvqBWLPPRVLzr8UfA9QPv6M3YBzDJA6Em5pYOboTYfZ/bB3CRvtXmZJe0gpd7Yv5EBqydgX+QzUj42k9PwuUelGzygL9sQNM7I+EySzz3hfeV+20NDJAauLcMLzvdarrKDs3PK0SmQDXqUPbTGamj5KINcp4eQAig==" Feb 09 04:43:04 volumio go-librespot[21449]: time="2026-02-09T04:43:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:04 volumio go-librespot[21449]: time="2026-02-09T04:43:04+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:04 volumio go-librespot[21449]: time="2026-02-09T04:43:04+07:00" level=debug msg="completed challenge" Feb 09 04:43:04 volumio go-librespot[21449]: time="2026-02-09T04:43: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 09 04:43:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:04 volumio volumio[21087]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:43:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:04 volumio volumio[21087]: Error: socket hang up Feb 09 04:43:04 volumio volumio[21087]: at connResetException (node:internal/errors:720:14) Feb 09 04:43:04 volumio volumio[21087]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 09 04:43:04 volumio volumio[21087]: at Socket.emit (node:events:526:35) Feb 09 04:43:04 volumio volumio[21087]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 09 04:43:04 volumio volumio[21087]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 09 04:43:04 volumio volumio[21087]: code: 'ECONNRESET', Feb 09 04:43:04 volumio volumio[21087]: response: undefined Feb 09 04:43:04 volumio volumio[21087]: } Feb 09 04:43:04 volumio volumio[21087]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:43:05 volumio sudo[21478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 04:42' Feb 09 04:43:05 volumio sudo[21478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:05 volumio sudo[21478]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 09 04:43:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:07 volumio volumio-remote-updater[643]: [2026-02-09 04:43:07] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 09 04:43:07 volumio volumio-remote-updater[643]: [2026-02-09 04:43:07] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 09 04:43:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:07 volumio go-librespot[21486]: go-librespot daemon starting... Feb 09 04:43:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 09 04:43:07 volumio systemd[1]: volumio.service: Consumed 55.804s CPU time. Feb 09 04:43:07 volumio go-librespot[21487]: time="2026-02-09T04:43:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:07 volumio go-librespot[21487]: time="2026-02-09T04:43:07+07:00" level=debug msg="app state loaded" Feb 09 04:43:07 volumio go-librespot[21487]: time="2026-02-09T04:43:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 04:43:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 04:43:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8210. Feb 09 04:43:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 04:43:07 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 04:43:07 volumio systemd[1]: volumio.service: Consumed 55.804s CPU time. Feb 09 04:43:07 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 04:43:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 04:43:07 volumio go-librespot[21487]: time="2026-02-09T04:43:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 09 04:43:07 volumio go-librespot[21487]: time="2026-02-09T04:43:07+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 09 04:43:07 volumio go-librespot[21487]: time="2026-02-09T04:43:07+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 09 04:43:08 volumio go-librespot[21487]: time="2026-02-09T04:43:08+07:00" level=info msg="zeroconf server listening on port 46133" Feb 09 04:43:08 volumio go-librespot[21487]: time="2026-02-09T04:43:08+07:00" level=debug msg="obtained new client token: AABTDETvqHfGFLXHlytP+LbHrzXgsgKNt08lb5pQIicQrqt7tk6llR8q/cCy2p3LFiU57jUCkp0N1ZOEDTkoKQ0YIK5Ix8d7dXA6TgZPmtGpI3f6v1GqVkK0ag+TQjG+xikEouQo8Xq6YpoWSLm3hgdXv/Zu0IDhsAzaJiuR0rCJ3e1P09N373P37sek7Nuy2DwG2AnqlTDZtC/qNJiBiJvhlMJoqdMnnhyPeWF+qbqIBZEW5cpyiEg=" Feb 09 04:43:08 volumio go-librespot[21487]: time="2026-02-09T04:43:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:08 volumio go-librespot[21487]: time="2026-02-09T04:43:08+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:08 volumio go-librespot[21487]: time="2026-02-09T04:43:08+07:00" level=debug msg="completed challenge" Feb 09 04:43:08 volumio go-librespot[21487]: time="2026-02-09T04:43: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 09 04:43:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:11 volumio volumio[21504]: info: ------------------------------------------- Feb 09 04:43:11 volumio volumio[21504]: info: ----- Volumio3 ---- Feb 09 04:43:11 volumio volumio[21504]: info: ------------------------------------------- Feb 09 04:43:11 volumio volumio[21504]: info: ----- System startup ---- Feb 09 04:43:11 volumio volumio[21504]: info: ------------------------------------------- Feb 09 04:43:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 09 04:43:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:11 volumio go-librespot[21526]: go-librespot daemon starting... Feb 09 04:43:11 volumio go-librespot[21527]: time="2026-02-09T04:43:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:11 volumio go-librespot[21527]: time="2026-02-09T04:43:11+07:00" level=debug msg="app state loaded" Feb 09 04:43:11 volumio go-librespot[21527]: time="2026-02-09T04:43:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:12 volumio volumio-remote-updater[643]: [2026-02-09 04:43:12] [connect] Successful connection Feb 09 04:43:12 volumio go-librespot[21527]: time="2026-02-09T04:43: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 09 04:43:12 volumio go-librespot[21527]: time="2026-02-09T04:43: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 09 04:43:12 volumio go-librespot[21527]: time="2026-02-09T04:43: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 09 04:43:12 volumio go-librespot[21527]: time="2026-02-09T04:43:12+07:00" level=info msg="zeroconf server listening on port 36485" Feb 09 04:43:12 volumio volumio[21504]: info: MYVOLUMIO Environment detected Feb 09 04:43:12 volumio go-librespot[21527]: time="2026-02-09T04:43:12+07:00" level=debug msg="obtained new client token: AADIDkypad9MqglgbQ7gK38W1dlshIaZvGbZdRHShfTYEw83W3sx7WtG+GmDO4rsnYaXdxYL+xPqGEWbL5CMR2sd77QgaEVUaQ7B+wePU2wnXO0vf7ZxMt2NFKJtqQ8zkGGfzJUAYSdyMXutkllDVabzd+BzA/z6pVBz/AdeoBk4KETRGlbej1vFzlAQWTVClsdRst/Fo063g/H25RDeP+Jqwbmc1JLCSy9sGrOe0MtX+UxhVfFbOpvIIw==" Feb 09 04:43:12 volumio volumio[21504]: info: Plugin folders cleanup Feb 09 04:43:12 volumio volumio[21504]: info: Scanning into folder /volumio/app/plugins/ Feb 09 04:43:12 volumio volumio[21504]: info: Scanning category audio_interface Feb 09 04:43:12 volumio volumio[21504]: info: Scanning category miscellanea Feb 09 04:43:12 volumio go-librespot[21527]: time="2026-02-09T04:43:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:12 volumio volumio[21504]: info: Scanning category music_service Feb 09 04:43:12 volumio volumio[21504]: info: Scanning category plugins.json Feb 09 04:43:12 volumio volumio[21504]: info: Scanning category system_controller Feb 09 04:43:12 volumio volumio[21504]: info: Scanning category user_interface Feb 09 04:43:12 volumio volumio[21504]: info: Scanning into folder /data/plugins/ Feb 09 04:43:12 volumio volumio[21504]: info: Scanning category music_service Feb 09 04:43:12 volumio volumio[21504]: info: Plugin folders cleanup completed Feb 09 04:43:12 volumio volumio[21504]: info: ------------------------------------------- Feb 09 04:43:12 volumio volumio[21504]: info: ----- Core plugins startup ---- Feb 09 04:43:12 volumio volumio[21504]: info: ------------------------------------------- Feb 09 04:43:12 volumio volumio[21504]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 04:43:12 volumio volumio[21504]: info: Adding plugin upnp to MyMusic Plugins Feb 09 04:43:12 volumio volumio[21504]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 04:43:12 volumio volumio[21504]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 04:43:12 volumio volumio[21504]: info: Loading plugins from folder /data/plugins/ Feb 09 04:43:12 volumio volumio[21504]: info: Loading plugin "system"... Feb 09 04:43:12 volumio go-librespot[21527]: time="2026-02-09T04:43:12+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:12 volumio go-librespot[21527]: time="2026-02-09T04:43:12+07:00" level=debug msg="completed challenge" Feb 09 04:43:12 volumio volumio[21504]: info: Loading plugin "appearance"... Feb 09 04:43:13 volumio go-librespot[21527]: time="2026-02-09T04:43: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 09 04:43:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:14 volumio volumio[21504]: info: Loading plugin "network"... Feb 09 04:43:14 volumio volumio[21504]: info: Refreshing Cached IP Addresses Feb 09 04:43:14 volumio sudo[21542]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:43:14 volumio sudo[21542]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:14 volumio volumio[21504]: info: Loading plugin "services"... Feb 09 04:43:14 volumio sudo[21542]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:14 volumio sudo[21544]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:43:14 volumio sudo[21544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:14 volumio volumio[21504]: info: Loading plugin "alsa_controller"... Feb 09 04:43:14 volumio sudo[21544]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:14 volumio sudo[21553]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 04:43:14 volumio sudo[21553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:15 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:43:15 volumio volumio[21504]: info: Loading plugin "wizard"... Feb 09 04:43:15 volumio volumio[21504]: info: Loading plugin "networkfs"... Feb 09 04:43:15 volumio volumio[21504]: info: Starting Udev Watcher for removable devices Feb 09 04:43:15 volumio volumio[21504]: info: Ignoring mount for partition: boot Feb 09 04:43:15 volumio volumio[21504]: info: Ignoring mount for partition: volumio Feb 09 04:43:15 volumio volumio[21504]: info: Ignoring mount for partition: volumio_data Feb 09 04:43:15 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:43:15 volumio volumio[21504]: info: Loading plugin "volumio_command_line_client"... Feb 09 04:43:15 volumio volumio[21504]: info: Loading plugin "upnp"... Feb 09 04:43:15 volumio volumio[21504]: info: [1770586995248] Starting Upmpd Daemon Feb 09 04:43:15 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:43:15 volumio volumio[21504]: info: Loading plugin "my_music"... Feb 09 04:43:15 volumio volumio[21504]: info: Loading plugin "mpd"... Feb 09 04:43:15 volumio volumio[21504]: info: Loading plugin "upnp_browser"... Feb 09 04:43:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 09 04:43:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:16 volumio go-librespot[21575]: go-librespot daemon starting... Feb 09 04:43:16 volumio go-librespot[21576]: time="2026-02-09T04:43:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:16 volumio go-librespot[21576]: time="2026-02-09T04:43:16+07:00" level=debug msg="app state loaded" Feb 09 04:43:16 volumio go-librespot[21576]: time="2026-02-09T04:43:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:16 volumio go-librespot[21576]: time="2026-02-09T04:43:16+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 09 04:43:16 volumio go-librespot[21576]: time="2026-02-09T04:43:16+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 09 04:43:16 volumio go-librespot[21576]: time="2026-02-09T04:43:16+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 09 04:43:16 volumio go-librespot[21576]: time="2026-02-09T04:43:16+07:00" level=info msg="zeroconf server listening on port 42167" Feb 09 04:43:16 volumio go-librespot[21576]: time="2026-02-09T04:43:16+07:00" level=debug msg="obtained new client token: AAAJ1h0mttgVbvT5myZnmmk3qT3oDGePS/hLBz0X6ayzwGFa8qJhiA/OxPxvYBBf5Uzs+hRWHf05+wZkH5oehRUMMJrZH/evvYn0GC6EXPjYjKtasaXTs8DrodHl7xW1wfkmAhnIMtiEYzFE/LZmFADlGtJTrRZmje+MJb26qrls+sYJhqRtyvgbZBBaT+pNF0hWgLA8rkJqioFx7Fd2U0xtw0Cqa2SkXOx3y9rnBem+jJyce0tb6rRXsw==" Feb 09 04:43:17 volumio go-librespot[21576]: time="2026-02-09T04:43:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:17 volumio go-librespot[21576]: time="2026-02-09T04:43:17+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:17 volumio go-librespot[21576]: time="2026-02-09T04:43:17+07:00" level=debug msg="completed challenge" Feb 09 04:43:17 volumio go-librespot[21576]: time="2026-02-09T04:43:17+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 09 04:43:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:17 volumio sudo[21553]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:18 volumio volumio[21504]: info: Starting UPNP Browser Feb 09 04:43:18 volumio volumio[21504]: info: Loading plugin "alarm-clock"... Feb 09 04:43:19 volumio volumio[21504]: info: Loading plugin "airplay_emulation"... Feb 09 04:43:19 volumio volumio[21504]: info: Starting Shairport Sync Feb 09 04:43:19 volumio volumio[21504]: info: Loading plugin "last_100"... Feb 09 04:43:19 volumio volumio[21504]: info: Loading plugin "webradio"... Feb 09 04:43:19 volumio volumio[21504]: info: Loading plugin "i2s_dacs"... Feb 09 04:43:19 volumio volumio[21504]: info: Loading plugin "volumiodiscovery"... Feb 09 04:43:19 volumio volumio[21504]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:43:19 volumio volumio[21504]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:43:19 volumio volumio[21504]: *** WARNING *** For more information see Feb 09 04:43:19 volumio volumio[21504]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:43:19 volumio volumio[21504]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:43:19 volumio volumio[21504]: *** WARNING *** For more information see Feb 09 04:43:19 volumio node[21504]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 04:43:19 volumio node[21504]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:43:19 volumio node[21504]: *** WARNING *** For more information see Feb 09 04:43:19 volumio node[21504]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 04:43:19 volumio node[21504]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 04:43:19 volumio node[21504]: *** WARNING *** For more information see Feb 09 04:43:19 volumio volumio[21504]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 04:43:19 volumio volumio[21504]: info: Discovery: Started advertising with name: Volumio Feb 09 04:43:19 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 04:43:19 volumio volumio[21504]: info: Loading plugin "spop"... Feb 09 04:43:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 09 04:43:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:20 volumio go-librespot[21586]: go-librespot daemon starting... Feb 09 04:43:20 volumio go-librespot[21587]: time="2026-02-09T04:43:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:20 volumio go-librespot[21587]: time="2026-02-09T04:43:20+07:00" level=debug msg="app state loaded" Feb 09 04:43:20 volumio go-librespot[21587]: time="2026-02-09T04:43:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:20 volumio go-librespot[21587]: time="2026-02-09T04:43:20+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 09 04:43:20 volumio go-librespot[21587]: time="2026-02-09T04:43:20+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 09 04:43:20 volumio go-librespot[21587]: time="2026-02-09T04:43:20+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 09 04:43:20 volumio go-librespot[21587]: time="2026-02-09T04:43:20+07:00" level=info msg="zeroconf server listening on port 35009" Feb 09 04:43:21 volumio go-librespot[21587]: time="2026-02-09T04:43:21+07:00" level=debug msg="obtained new client token: AACSwDaxXL1rvC4ljmVFQPAcVEmHk3JBwVZpJWwunFoeIeOUl/AF9U44EKkE2avc96OdwO9wla7DH0VkcqptbELCUJ2JNbm4ORly7dT0adBNEOiDOyjQNfT1mHcxdxJlQZqo2AgYC+8A5Uc2wR/8i2n+kvZ/qR5vTNYzJ8qdmYvxUMZ5aAhAnPpISLH4L4eeOkFEn0SfykYJ3iPnrCJYnnJOuzpIU4LAvP3uDPp2VboT46GvdgFuarU=" Feb 09 04:43:21 volumio go-librespot[21587]: time="2026-02-09T04:43:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:21 volumio go-librespot[21587]: time="2026-02-09T04:43:21+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:21 volumio go-librespot[21587]: time="2026-02-09T04:43:21+07:00" level=debug msg="completed challenge" Feb 09 04:43:21 volumio volumio[21504]: info: Loading plugin "ytcr"... Feb 09 04:43:21 volumio go-librespot[21587]: time="2026-02-09T04:43:21+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 09 04:43:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:24 volumio volumio[21504]: info: Loading plugin "ytmusic"... Feb 09 04:43:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 09 04:43:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:24 volumio go-librespot[21595]: go-librespot daemon starting... Feb 09 04:43:24 volumio go-librespot[21596]: time="2026-02-09T04:43:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:24 volumio go-librespot[21596]: time="2026-02-09T04:43:24+07:00" level=debug msg="app state loaded" Feb 09 04:43:24 volumio go-librespot[21596]: time="2026-02-09T04:43:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:24 volumio volumio-remote-updater[643]: [2026-02-09 04:43:24] [connect] Successful connection Feb 09 04:43:25 volumio volumio[21504]: info: Loading plugin "outputs"... Feb 09 04:43:25 volumio volumio[21504]: info: Loading plugin "albumart"... Feb 09 04:43:25 volumio go-librespot[21596]: time="2026-02-09T04:43:25+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 09 04:43:25 volumio go-librespot[21596]: time="2026-02-09T04:43:25+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 09 04:43:25 volumio go-librespot[21596]: time="2026-02-09T04:43:25+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 09 04:43:25 volumio volumio[21504]: info: Plugin example_plugin is not enabled Feb 09 04:43:25 volumio volumio[21504]: info: Loading plugin "inputs"... Feb 09 04:43:25 volumio volumio[21504]: info: Loading plugin "updater_comm"... Feb 09 04:43:25 volumio go-librespot[21596]: time="2026-02-09T04:43:25+07:00" level=info msg="zeroconf server listening on port 37617" Feb 09 04:43:25 volumio volumio[21504]: info: Plugin mpdemulation is not enabled Feb 09 04:43:25 volumio volumio[21504]: info: Loading plugin "rest_api"... Feb 09 04:43:25 volumio go-librespot[21596]: time="2026-02-09T04:43:25+07:00" level=debug msg="obtained new client token: AAAJ2YzFQvDpOAcTD0wiA0ecHey0DSXhHf696FNB4oiM5h1VEF4zy/MyI7WNesUFTEdA5xzmsNRqPGY8FUcN4os+iEVwT/pCPSm4ifWaAOneFuyRB2nOLiwxAGkBz3sdC2B/ki+q6/VNPJNeepNaMq060EBkkjnOEyQnAC3qqA2P/VAa23WSfUckXIrpfngQ85qxbTgt5qX4054D4TjgjH/GGXqIYoWtRfzz0DvKObqRqinQM7XzJ3vF8A==" Feb 09 04:43:25 volumio volumio[21504]: info: Loading plugin "websocket"... Feb 09 04:43:25 volumio volumio[21504]: info: Starting Socket.io Server version 1.7.4 Feb 09 04:43:25 volumio volumio[21504]: info: Loading plugin "RoonBridge"... Feb 09 04:43:25 volumio go-librespot[21596]: time="2026-02-09T04:43:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:25 volumio go-librespot[21596]: time="2026-02-09T04:43:25+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:25 volumio go-librespot[21596]: time="2026-02-09T04:43:25+07:00" level=debug msg="completed challenge" Feb 09 04:43:25 volumio go-librespot[21596]: time="2026-02-09T04:43:25+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 09 04:43:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:26 volumio volumio[21504]: info: Applying required configuration parameters for plugin RoonBridge Feb 09 04:43:26 volumio volumio[21504]: info: Loading i18n strings for locale en Feb 09 04:43:26 volumio volumio[21504]: Updating browse sources language Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:43:26 volumio volumio[21617]: Forking 3 albumart workers Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::initPlayerControls Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:43:26 volumio volumio[21504]: Express server listening on port 3000 Feb 09 04:43:26 volumio volumio[21504]: [Metrics] WebUI: 16s 173.60ms Feb 09 04:43:26 volumio volumio[21504]: info: CoreStateMachine::resetVolumioState Feb 09 04:43:26 volumio volumio[21504]: info: CoreStateMachine::getcurrentVolume Feb 09 04:43:26 volumio volumio[21504]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:43:26 volumio sudo[21661]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 04:43:26 volumio sudo[21664]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 04:43:26 volumio sudo[21664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:26 volumio sudo[21661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:26 volumio sudo[21661]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:26 volumio volumio[21504]: info: Volumio Network Manager: Network status updated: 1 Feb 09 04:43:26 volumio sudo[21664]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:27 volumio volumio[21504]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:43:27 volumio volumio[21504]: info: CoreStateMachine::pushState Feb 09 04:43:27 volumio volumio[21504]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::volumioPushState Feb 09 04:43:27 volumio volumio[21504]: info: CoreStateMachine::updateTrackBlock Feb 09 04:43:27 volumio volumio[21504]: info: CorePlayQueue::getTrackBlock Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:43:27 volumio volumio-remote-updater[643]: [2026-02-09 04:43:27] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770587004 101 Feb 09 04:43:27 volumio volumio[21504]: 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 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:27 volumio volumio[21504]: info: Reloading queue from file Feb 09 04:43:27 volumio volumio[21504]: info: CoreStateMachine::setRepeat null single undefined Feb 09 04:43:27 volumio volumio[21504]: info: CoreStateMachine::pushState Feb 09 04:43:27 volumio volumio[21504]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::volumioPushState Feb 09 04:43:27 volumio volumio[21504]: info: CoreStateMachine::setRandom null Feb 09 04:43:27 volumio volumio[21504]: info: CoreStateMachine::pushState Feb 09 04:43:27 volumio volumio[21504]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::volumioPushState Feb 09 04:43:27 volumio volumio[21504]: info: Setting Device type: Raspberry PI Feb 09 04:43:27 volumio volumio[21504]: info: Completed loading Core Plugins Feb 09 04:43:27 volumio volumio[21504]: info: Preparing to generate the ALSA configuration file Feb 09 04:43:27 volumio volumio[21504]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:43:27 volumio volumio[21504]: info: CoreStateMachine::pushState Feb 09 04:43:27 volumio volumio[21504]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::volumioPushState Feb 09 04:43:27 volumio volumio[21504]: info: Asound.conf file unchanged, so no further update is needed Feb 09 04:43:27 volumio volumio[21504]: info: Output device has changed, restarting MPD Feb 09 04:43:27 volumio volumio[21504]: info: Output device has changed, restarting Shairport Sync Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:27 volumio sudo[21678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 04:43:27 volumio sudo[21678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:27 volumio sudo[21680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:43:27 volumio sudo[21680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:27 volumio sudo[21680]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:27 volumio volumio[21504]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:43:27 volumio volumio[21504]: info: ___________ START PLUGINS ___________ Feb 09 04:43:27 volumio sudo[21678]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:27 volumio volumio[21504]: info: ControllerMpd::onStart: Initializing MPD Feb 09 04:43:27 volumio volumio[21504]: info: Creating MPD Configuration file Feb 09 04:43:27 volumio sudo[21682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:43:27 volumio sudo[21682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:27 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:43:27 volumio volumio[21504]: info: [1770587007868] CoreMusicLibrary::Adding element Media Servers Feb 09 04:43:27 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:43:27 volumio sudo[21693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 04:43:27 volumio sudo[21693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:27 volumio sudo[21691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 04:43:27 volumio sudo[21691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:28 volumio sudo[21691]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:28 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 04:43:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 04:43:28 volumio systemd[1]: mpd.service: Consumed 7.215s CPU time. Feb 09 04:43:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 04:43:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 04:43:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 04:43:28 volumio volumio[21504]: info: UPNP Browser: Client initialized successfully Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 04:43:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 04:43:28 volumio volumio[21504]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:28 volumio volumio[21504]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:43:28 volumio volumio[21504]: info: [1770587008286] CoreMusicLibrary::Adding element Last_100 Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:43:28 volumio volumio[21504]: info: [1770587008305] CoreMusicLibrary::Adding element Webradio Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:43:28 volumio volumio[21504]: info: Initializing BBC Radios Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:28 volumio volumio[21504]: info: Creating Spotify config file Feb 09 04:43:28 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:28 volumio sudo[21701]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 04:43:28 volumio sudo[21701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 04:43:28 volumio sudo[21701]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 09 04:43:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:29 volumio go-librespot[21722]: go-librespot daemon starting... Feb 09 04:43:29 volumio go-librespot[21723]: time="2026-02-09T04:43:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:29 volumio volumio[21627]: Starting albumart workers Feb 09 04:43:29 volumio volumio[21628]: Starting albumart workers Feb 09 04:43:29 volumio go-librespot[21723]: time="2026-02-09T04:43:29+07:00" level=info msg="zeroconf server listening on port 33099" Feb 09 04:43:29 volumio volumio[21504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:43:29 volumio volumio[21504]: info: [1770587009925] CoreMusicLibrary::Adding element YouTube Music Feb 09 04:43:29 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:43:29 volumio volumio[21504]: Cannot find translation for source YouTube Music Feb 09 04:43:29 volumio volumio[21504]: info: Volumio Calling Home Feb 09 04:43:29 volumio volumio[21629]: Starting albumart workers Feb 09 04:43:30 volumio sudo[21731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 09 04:43:30 volumio sudo[21731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:30 volumio sudo[21731]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:30 volumio volumio[21504]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:43:30 volumio volumio[21504]: info: Discovery: Found device Volumio Feb 09 04:43:30 volumio volumio[21504]: info: CoreCommandRouter::volumioGetState Feb 09 04:43:30 volumio volumio[21504]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:30 volumio volumio[21504]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 09 04:43:30 volumio volumio[21504]: info: Discovery: Found device Volumio Feb 09 04:43:30 volumio volumio[21504]: info: CoreCommandRouter::volumioGetState Feb 09 04:43:30 volumio volumio[21504]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:30 volumio volumio[21504]: info: MPD Permissions set Feb 09 04:43:30 volumio volumio[21504]: info: MPD Permissions set Feb 09 04:43:30 volumio volumio[21504]: info: Upmpdcli Daemon Started Feb 09 04:43:30 volumio volumio[21504]: info: Spotify config file written Feb 09 04:43:31 volumio sudo[21737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 04:43:31 volumio sudo[21737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:31 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 04:43:31 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 04:43:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:31 volumio go-librespot[21739]: go-librespot daemon starting... Feb 09 04:43:31 volumio sudo[21737]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:31 volumio go-librespot[21740]: time="2026-02-09T04:43:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:31 volumio go-librespot[21740]: time="2026-02-09T04:43:31+07:00" level=debug msg="app state loaded" Feb 09 04:43:31 volumio go-librespot[21740]: time="2026-02-09T04:43:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:31 volumio volumio[21504]: 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 09 04:43:31 volumio volumio[21504]: info: Volumio called home Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 04:43:31 volumio volumio[21504]: info: No need to fix Spotify hosts Feb 09 04:43:31 volumio go-librespot[21740]: time="2026-02-09T04:43:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:43:31 volumio go-librespot[21740]: time="2026-02-09T04:43:31+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 09 04:43:31 volumio go-librespot[21740]: time="2026-02-09T04:43:31+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 09 04:43:32 volumio go-librespot[21740]: time="2026-02-09T04:43:32+07:00" level=info msg="zeroconf server listening on port 35145" Feb 09 04:43:32 volumio go-librespot[21740]: time="2026-02-09T04:43:32+07:00" level=debug msg="obtained new client token: AACwaZd4cZ8kCI2eqdTttbvgEwpd/B/82B5Z4RvEHffAFTKdln9A692+wa637s6p0Erco4hQkx8oO3cGT0OW1ZS9j/HXu1LSa/lOeqTtfvhgFCApbD/79zfUjxQW/0xtDuyGFcV8sMfx3hvV7dDXbMRJpzssHFhhvSx5ucz3rTGji65ZIqXHNdqcsqP7/h48x2+sR2VSyaxNIpdn85fJtD/g04HuGPOnMVqW08B3aNaTxFtP+HvAOIs=" Feb 09 04:43:32 volumio go-librespot[21740]: time="2026-02-09T04:43:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:32 volumio go-librespot[21740]: time="2026-02-09T04:43:32+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:32 volumio go-librespot[21740]: time="2026-02-09T04:43:32+07:00" level=debug msg="completed challenge" Feb 09 04:43:32 volumio volumio[21504]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:43:32 volumio volumio[21504]: SPOTIFY: BQCq_RyQr_aGcu_3NyAbNYmU_6fw4Km5wy-Wqdh9n1w43vYxIxDoiY3I1B03zCuUcpOdSghTbRX9jKbUnSCqYYqmJkA4JITygUTlz0o6mfmVw63Fm1NeD81AsjysiCuUF3uJJWKcHDgIByxxftAF7lm-H60PpiUX5NIjRHF1rVEwKOhduF0Td2ysUKWEyCiYwRl1WZKKCyov3SMhX1rRQxX3J2XPuNg-aw-RZBz5FsYcxqNf4DPfqlLr5god-Unw3H8DM4opWX5aqEiQyaSDNtzbJsgsAY7XHcSUBPNWxjvwkTnwSUtqRSTJ Feb 09 04:43:32 volumio volumio[21504]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 09 04:43:32 volumio volumio[21504]: info: New Spotify access token = BQCq_RyQr_aGcu_3NyAbNYmU_6fw4Km5wy-Wqdh9n1w43vYxIxDoiY3I1B03zCuUcpOdSghTbRX9jKbUnSCqYYqmJkA4JITygUTlz0o6mfmVw63Fm1NeD81AsjysiCuUF3uJJWKcHDgIByxxftAF7lm-H60PpiUX5NIjRHF1rVEwKOhduF0Td2ysUKWEyCiYwRl1WZKKCyov3SMhX1rRQxX3J2XPuNg-aw-RZBz5FsYcxqNf4DPfqlLr5god-Unw3H8DM4opWX5aqEiQyaSDNtzbJsgsAY7XHcSUBPNWxjvwkTnwSUtqRSTJ Feb 09 04:43:32 volumio volumio[21504]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 04:43:32 volumio go-librespot[21740]: time="2026-02-09T04:43:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:43:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:32 volumio volumio[21504]: info: Starting Shairport Sync Feb 09 04:43:32 volumio volumio[21504]: info: Starting Shairport Sync Feb 09 04:43:32 volumio volumio[21504]: info: Starting Shairport Sync Feb 09 04:43:32 volumio sudo[21778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:43:32 volumio sudo[21778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:32 volumio sudo[21780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:43:32 volumio sudo[21780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 04:43:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 04:43:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:43:32 volumio systemd[1]: shairport-sync.service: Consumed 2.318s CPU time. Feb 09 04:43:32 volumio sudo[21782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 04:43:32 volumio sudo[21782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:43:32 volumio volumio[21504]: info: CoreCommandRouter::volumioGetState Feb 09 04:43:32 volumio volumio[21504]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:32 volumio sudo[21778]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:33 volumio volumio[21504]: info: Shairport-Sync Started Feb 09 04:43:33 volumio volumio[21504]: Error adding Membership: Error: addMembership EINVAL Feb 09 04:43:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 04:43:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 04:43:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:43:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 04:43:33 volumio volumio[21504]: 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 09 04:43:33 volumio volumio[21504]: info: Spotify Successfully logged in Feb 09 04:43:33 volumio sudo[21780]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:33 volumio volumio[21504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 04:43:33 volumio volumio[21504]: info: [1770587013292] CoreMusicLibrary::Adding element Spotify Feb 09 04:43:33 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 04:43:33 volumio volumio[21504]: Cannot find translation for source YouTube Music Feb 09 04:43:33 volumio volumio[21504]: Cannot find translation for source Spotify Feb 09 04:43:33 volumio sudo[21782]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:33 volumio volumio[21504]: info: Shairport-Sync Started Feb 09 04:43:33 volumio volumio[21504]: info: Shairport-Sync Started Feb 09 04:43:33 volumio volumio[21504]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 04:43:34 volumio volumio[21504]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 04:43:34 volumio volumio[21504]: info: VolumeController:: Volume=100 Mute =false Feb 09 04:43:34 volumio volumio[21504]: info: CoreCommandRouter::volumioGetState Feb 09 04:43:34 volumio volumio[21504]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:34 volumio volumio[21504]: info: CoreStateMachine::pushState Feb 09 04:43:34 volumio volumio[21504]: info: CorePlayQueue::getTrack 0 Feb 09 04:43:34 volumio volumio[21504]: info: CoreCommandRouter::volumioPushState Feb 09 04:43:35 volumio volumio[21504]: info: go-librespot daemon successfully initialized Feb 09 04:43:35 volumio mpd[21721]: 2026-02-09T04:43:35 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 04:43:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 09 04:43:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:35 volumio go-librespot[21831]: go-librespot daemon starting... Feb 09 04:43:35 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 04:43:35 volumio sudo[21693]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:35 volumio sudo[21682]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:35 volumio go-librespot[21832]: time="2026-02-09T04:43:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:35 volumio go-librespot[21832]: time="2026-02-09T04:43:35+07:00" level=debug msg="app state loaded" Feb 09 04:43:35 volumio go-librespot[21832]: time="2026-02-09T04:43:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:35 volumio volumio[21504]: error: MPD error: The expression evaluated to a falsy value: Feb 09 04:43:35 volumio volumio[21504]: assert.ok(self.idling) Feb 09 04:43:35 volumio volumio[21504]: error: The expression evaluated to a falsy value: Feb 09 04:43:35 volumio volumio[21504]: assert.ok(self.idling) Feb 09 04:43:36 volumio volumio[21504]: info: Completed starting Core Plugins Feb 09 04:43:36 volumio volumio[21504]: info: ------------------------------------------- Feb 09 04:43:36 volumio volumio[21504]: info: ----- MyVolumio plugins startup ---- Feb 09 04:43:36 volumio volumio[21504]: info: ------------------------------------------- Feb 09 04:43:36 volumio volumio[21504]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 04:43:36 volumio volumio[21504]: info: MPD running with PID21721 Feb 09 04:43:36 volumio volumio[21504]: ,establishing connection Feb 09 04:43:36 volumio volumio[21504]: error: updateQueue error: null Feb 09 04:43:36 volumio volumio[21504]: error: updateQueue error: null Feb 09 04:43:36 volumio go-librespot[21832]: time="2026-02-09T04:43:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:43:36 volumio go-librespot[21832]: time="2026-02-09T04:43:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:43:36 volumio go-librespot[21832]: time="2026-02-09T04:43:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:43:36 volumio go-librespot[21832]: time="2026-02-09T04:43:36+07:00" level=info msg="zeroconf server listening on port 35665" Feb 09 04:43:36 volumio go-librespot[21832]: time="2026-02-09T04:43:36+07:00" level=debug msg="obtained new client token: AABXB6F/mvgvnhawFu0/W/ApWspYuLkTJBA/wGVNcKIv+9TksM+4zm7kAb/vpGHbT2mK6fUOicjO3Z/zTQsbPMjS5puTEiF2BvHCxGG/nXrWcfGOrtDJEHx7u0UoJT16mH3fI4JxCHGkLcYMLLMuH1ZtfLOsMnPrhdb+KM2A5lnTnd7e89vaKR4k5kd+PaUVhxecFGZtdAj4sbNd6bWNQQmA2mAmgt2zao2w8mI9rbvmLJyICp85Odfbig==" Feb 09 04:43:36 volumio go-librespot[21832]: time="2026-02-09T04:43:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:36 volumio go-librespot[21832]: time="2026-02-09T04:43:36+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:36 volumio go-librespot[21832]: time="2026-02-09T04:43:36+07:00" level=debug msg="completed challenge" Feb 09 04:43:36 volumio go-librespot[21832]: time="2026-02-09T04:43:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:43:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:38 volumio volumio[21504]: info: Initializing connection to go-librespot Websocket Feb 09 04:43:38 volumio volumio[21504]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:43:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 09 04:43:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:40 volumio go-librespot[21841]: go-librespot daemon starting... Feb 09 04:43:40 volumio go-librespot[21842]: time="2026-02-09T04:43:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:40 volumio go-librespot[21842]: time="2026-02-09T04:43:40+07:00" level=debug msg="app state loaded" Feb 09 04:43:40 volumio go-librespot[21842]: time="2026-02-09T04:43:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:40 volumio go-librespot[21842]: time="2026-02-09T04:43:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:43:40 volumio go-librespot[21842]: time="2026-02-09T04:43:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:43:40 volumio go-librespot[21842]: time="2026-02-09T04:43:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:43:40 volumio go-librespot[21842]: time="2026-02-09T04:43:40+07:00" level=info msg="zeroconf server listening on port 36325" Feb 09 04:43:40 volumio volumio[21504]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 04:43:40 volumio go-librespot[21842]: time="2026-02-09T04:43:40+07:00" level=debug msg="obtained new client token: AADMwWtmf1Y5PqfM/2dusyArOtuHR2WktG27+mZN/qKSZyxb0smw+Vkl1YvnyOr5zq5zF+sKqhWiZ8Ko3RbtvcfBWLrjwzeSOym9x6LXGtIduj6v1cbv04SFHu6T4mhDVU+VO83w0ru5qq3f8v3zjuvxiOVPZ3a6Mhfl3OviAuSwdo9BPNSgP1kjjj1MXl8qqHMPooQNmM7hgNMMCmyBoEC9dSf2u1RNTwkqtoaNkBQyR+f3ZQ6OO54V2A==" Feb 09 04:43:40 volumio go-librespot[21842]: time="2026-02-09T04:43:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:41 volumio go-librespot[21842]: time="2026-02-09T04:43:41+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:41 volumio go-librespot[21842]: time="2026-02-09T04:43:41+07:00" level=debug msg="completed challenge" Feb 09 04:43:41 volumio go-librespot[21842]: time="2026-02-09T04:43:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:43:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:41 volumio volumio[21504]: info: Initializing connection to go-librespot Websocket Feb 09 04:43:41 volumio volumio[21504]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:43:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 09 04:43:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:44 volumio volumio[21504]: info: Initializing connection to go-librespot Websocket Feb 09 04:43:44 volumio volumio[21504]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:43:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:44 volumio go-librespot[21850]: go-librespot daemon starting... Feb 09 04:43:44 volumio go-librespot[21851]: time="2026-02-09T04:43:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:44 volumio go-librespot[21851]: time="2026-02-09T04:43:44+07:00" level=debug msg="app state loaded" Feb 09 04:43:44 volumio go-librespot[21851]: time="2026-02-09T04:43:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:44 volumio go-librespot[21851]: time="2026-02-09T04:43:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:43:44 volumio go-librespot[21851]: time="2026-02-09T04:43:44+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 09 04:43:44 volumio go-librespot[21851]: time="2026-02-09T04:43:44+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 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 09 04:43:44 volumio go-librespot[21851]: time="2026-02-09T04:43:44+07:00" level=info msg="zeroconf server listening on port 38821" Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 09 04:43:44 volumio volumio[21504]: info: Adding plugin bluetooth to MyMusic Plugins Feb 09 04:43:44 volumio volumio[21504]: info: Adding plugin multiroom to MyMusic Plugins Feb 09 04:43:44 volumio volumio[21504]: info: Adding plugin metavolumio to MyMusic Plugins Feb 09 04:43:44 volumio volumio[21504]: info: Adding plugin cd_controller to MyMusic Plugins Feb 09 04:43:44 volumio volumio[21504]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 09 04:43:44 volumio volumio[21504]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 09 04:43:44 volumio volumio[21504]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 09 04:43:44 volumio volumio[21504]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 09 04:43:45 volumio go-librespot[21851]: time="2026-02-09T04:43:45+07:00" level=debug msg="obtained new client token: AADsJC9vzCMeSRW8/ryX+cYzV9x+pOvAJrKOMSj3jwrntQtbOTaEdBPXyYT6TCIp7m8w4FJ2bBNE/ZbMaEn+5TQkkSD3nvSkO6wHUTsLy3K+70pTBVHrgiFXa5oQbZs1hejgWM10hjxgqgcshD/IExBu1oADSdSWa8Jc3XugojkMnAUz03nrJuRKrXf8bBW9m02J08PFMAHs7SlHlkpjahjSZZlaNtgs0sXFkvw4BJ8k3VtRdYjOunQ=" Feb 09 04:43:45 volumio go-librespot[21851]: time="2026-02-09T04:43:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:45 volumio go-librespot[21851]: time="2026-02-09T04:43:45+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:45 volumio go-librespot[21851]: time="2026-02-09T04:43:45+07:00" level=debug msg="completed challenge" Feb 09 04:43:45 volumio go-librespot[21851]: time="2026-02-09T04:43:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:43:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:46 volumio volumio[21504]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 09 04:43:46 volumio volumio[21504]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 09 04:43:46 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:46 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:46 volumio volumio[21504]: info: Starting MyVolumio Remote Streaming Endpoints Feb 09 04:43:46 volumio volumio[21504]: info: MyVolumio login type: Token Feb 09 04:43:46 volumio volumio[21504]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 09 04:43:46 volumio volumio[21504]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 09 04:43:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 09 04:43:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:48 volumio volumio[21504]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 09 04:43:48 volumio volumio[21504]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 09 04:43:48 volumio volumio[21504]: info: Streaming services startup Feb 09 04:43:48 volumio volumio[21504]: info: Starting Streaming Daemon Feb 09 04:43:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:48 volumio go-librespot[21872]: go-librespot daemon starting... Feb 09 04:43:48 volumio volumio[21504]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 09 04:43:48 volumio sudo[21874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:43:48 volumio sudo[21874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:48 volumio go-librespot[21877]: time="2026-02-09T04:43:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:48 volumio go-librespot[21877]: time="2026-02-09T04:43:48+07:00" level=debug msg="app state loaded" Feb 09 04:43:48 volumio go-librespot[21877]: time="2026-02-09T04:43:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:48 volumio sudo[21874]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:48 volumio volumio[21504]: info: Initializing connection to go-librespot Websocket Feb 09 04:43:48 volumio volumio[21504]: error: Cannot start Volumio Streaming Daemon Feb 09 04:43:48 volumio volumio[21504]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:43:48 volumio volumio[21504]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:43:48 volumio go-librespot[21877]: time="2026-02-09T04:43:48+07:00" level=debug msg="new websocket client" Feb 09 04:43:48 volumio volumio[21504]: info: Connection to go-librespot Websocket established Feb 09 04:43:49 volumio go-librespot[21877]: time="2026-02-09T04:43:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:43:49 volumio go-librespot[21877]: time="2026-02-09T04:43:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 09 04:43:49 volumio go-librespot[21877]: time="2026-02-09T04:43:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 09 04:43:49 volumio go-librespot[21877]: time="2026-02-09T04:43:49+07:00" level=info msg="zeroconf server listening on port 38971" Feb 09 04:43:49 volumio go-librespot[21877]: time="2026-02-09T04:43:49+07:00" level=debug msg="obtained new client token: AABVflbk82I1LcstJc9amP806vbsNnRR5RAfKa/sEdLnDnpJi3Cugs6Cp4uRf1UICr2uM5hwgr570b+5E25Nf8dCLW/e6vAi1PGr5UqdP48pnpE+Z7enHaBreni+JApTt8xoqe0GxUEbER5EvztBWMCHZs3OruiefC8vMoYY3K7yj/2yfycXGo5z1Wt5XzrsuMh7SM0TGX8oyPqiTd5qd0q9BlNQ1OMs3/6OuqL0rMFOK3RCVONlCu1A0A==" Feb 09 04:43:49 volumio go-librespot[21877]: time="2026-02-09T04:43:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 09 04:43:49 volumio go-librespot[21877]: time="2026-02-09T04:43:49+07:00" level=debug msg="completed keyexchange" Feb 09 04:43:49 volumio go-librespot[21877]: time="2026-02-09T04:43:49+07:00" level=debug msg="completed challenge" Feb 09 04:43:49 volumio go-librespot[21877]: time="2026-02-09T04:43:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 09 04:43:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 09 04:43:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 09 04:43:49 volumio volumio[21504]: info: Connection to go-librespot Websocket closed Feb 09 04:43:49 volumio volumio[21504]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 09 04:43:50 volumio volumio[21504]: info: MyVolumio token set successfully Feb 09 04:43:50 volumio volumio[21504]: info: MYVOLUMIO: Adding device Feb 09 04:43:50 volumio volumio[21504]: info: MYVOLUMIO: Evaluating Server Feb 09 04:43:51 volumio volumio[21504]: info: MyVolumio status changed Feb 09 04:43:51 volumio volumio[21504]: info: Streaming services startup Feb 09 04:43:51 volumio volumio[21504]: info: Starting Streaming Daemon Feb 09 04:43:51 volumio volumio[21504]: info: Removing browser output: myVolumio user plan is not superstar Feb 09 04:43:51 volumio volumio[21504]: info: Removing audio output: Feb 09 04:43:51 volumio volumio[21504]: info: Stoppping Tunnel 1 Feb 09 04:43:51 volumio sudo[21908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 09 04:43:51 volumio sudo[21908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:51 volumio sudo[21908]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:51 volumio volumio[21504]: error: Cannot start Volumio Streaming Daemon Feb 09 04:43:51 volumio volumio[21504]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 09 04:43:51 volumio volumio[21504]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 09 04:43:51 volumio sudo[21911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 09 04:43:51 volumio sudo[21911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:51 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 09 04:43:51 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 09 04:43:51 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 09 04:43:51 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 09 04:43:51 volumio volumio[21504]: info: Setting Geolocation for MyVolumio to as1 Feb 09 04:43:51 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:51 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:51 volumio volumio[21504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 04:43:51 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 09 04:43:51 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 09 04:43:51 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 09 04:43:51 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 09 04:43:51 volumio sudo[21911]: pam_unix(sudo:session): session closed for user root Feb 09 04:43:51 volumio volumio[21504]: info: Remote SSH Stopped Feb 09 04:43:51 volumio volumio[21504]: info: Getting Spotify volume Feb 09 04:43:51 volumio volumio[21504]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:43:51 volumio volumio[21504]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 09 04:43:51 volumio volumio[21504]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 09 04:43:51 volumio volumio[21504]: errno: -111, Feb 09 04:43:51 volumio volumio[21504]: code: 'ECONNREFUSED', Feb 09 04:43:51 volumio volumio[21504]: syscall: 'connect', Feb 09 04:43:51 volumio volumio[21504]: address: '127.0.0.1', Feb 09 04:43:51 volumio volumio[21504]: port: 9879, Feb 09 04:43:51 volumio volumio[21504]: response: undefined Feb 09 04:43:51 volumio volumio[21504]: } Feb 09 04:43:51 volumio volumio[21504]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 04:43:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 09 04:43:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 04:43:52 volumio go-librespot[21925]: go-librespot daemon starting... Feb 09 04:43:52 volumio go-librespot[21926]: time="2026-02-09T04:43:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 09 04:43:52 volumio go-librespot[21926]: time="2026-02-09T04:43:52+07:00" level=debug msg="app state loaded" Feb 09 04:43:52 volumio go-librespot[21926]: time="2026-02-09T04:43:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 04:43:53 volumio go-librespot[21926]: time="2026-02-09T04:43:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 09 04:43:53 volumio go-librespot[21926]: time="2026-02-09T04:43:53+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 09 04:43:53 volumio go-librespot[21926]: time="2026-02-09T04:43:53+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 09 04:43:53 volumio sudo[21936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 04:42' Feb 09 04:43:53 volumio sudo[21936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 04:43:53 volumio go-librespot[21926]: time="2026-02-09T04:43:53+07:00" level=info msg="zeroconf server listening on port 34985" Feb 09 04:43:53 volumio go-librespot[21926]: time="2026-02-09T04:43:53+07:00" level=debug msg="obtained new client token: AADWEBJ4YpW29GnXwIf/H6ir6xnSV05Ph6+Q+s9LNyk/IeCKQZMTgB2iwzc4DXTNg8Rimt1DCGbGzsGzJW1U8oQ2AW76U4ArSk79XhiX7p33M+Czxo/pJTHq1nsYeDJFFIgB0woI2T1g728BnUNUW5SSQcbzjI8bRv0eViQuEd1oI9QfBu+XJEwvhvLBBvI2YLstezyr74j29Pn2H9ggzKbLKoZMfb4mzu8ArMUMF7gH2nn0uaVE7dnI/A==" Feb 09 04:43:53 volumio go-librespot[21926]: time="2026-02-09T04:43:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" 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"