Feb 26 00:22:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44.
Feb 26 00:22:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:00 volumio go-librespot[32571]: go-librespot daemon starting...
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=debug msg="app state loaded"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=info msg="zeroconf server listening on port 35087"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=debug msg="obtained new client token: AACgV/cd3xhsHlNMt5lcctz+31oxujQTyhE3kYrz/6HCjOgdlrvAMFar0XCoNmmQ85ZRDRmp52IoejfrMjQm0XDKC1U/l5j1bIJ0KqlgIAP8CvVqtfXVXnPh1qUJvOUHlyzZTDCHfRUYe6tI96t4TOw/sEmXj+2aiWEIrOczx4fuoc/1bMz4AckxmXWz0d8mwO6UYeiN7fGEzRGBqBaaxNJr1d2S2TY35b4by3Dh7QZLQwPSh5ePNCOJWg=="
Feb 26 00:22:01 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=debug msg="completed keyexchange"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=debug msg="completed challenge"
Feb 26 00:22:01 volumio go-librespot[32572]: time="2026-02-26T00:22:01-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 26 00:22:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:22:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:22:02 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45.
Feb 26 00:22:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:04 volumio go-librespot[32594]: go-librespot daemon starting...
Feb 26 00:22:04 volumio go-librespot[32595]: time="2026-02-26T00:22:04-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:04 volumio go-librespot[32595]: time="2026-02-26T00:22:04-06:00" level=debug msg="app state loaded"
Feb 26 00:22:04 volumio go-librespot[32595]: time="2026-02-26T00:22:04-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:04 volumio go-librespot[32595]: time="2026-02-26T00:22:04-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 26 00:22:04 volumio volumio[32107]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 26 00:22:04 volumio volumio[32107]: info: Adding plugin multiroom to MyMusic Plugins
Feb 26 00:22:04 volumio volumio[32107]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 26 00:22:04 volumio volumio[32107]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 26 00:22:04 volumio volumio[32107]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 26 00:22:04 volumio volumio[32107]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 26 00:22:04 volumio volumio[32107]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 26 00:22:04 volumio volumio[32107]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 26 00:22:04 volumio go-librespot[32595]: time="2026-02-26T00:22:04-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 26 00:22:04 volumio go-librespot[32595]: time="2026-02-26T00:22:04-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 26 00:22:04 volumio go-librespot[32595]: time="2026-02-26T00:22:04-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 26 00:22:04 volumio go-librespot[32595]: time="2026-02-26T00:22:04-06:00" level=info msg="zeroconf server listening on port 34519"
Feb 26 00:22:05 volumio go-librespot[32595]: time="2026-02-26T00:22:05-06:00" level=debug msg="obtained new client token: AACblqtcsqnIo7m1W4XBfISvNFYIY036ZsRvbmJnZWpyqQF3RCLAB24uJ51xjwAx1z+v6+FwHNFblsmwa02CPWE6hBfSLuHHIp6mYZNyvAUaTlsN96bYea48It2dG7RudKtjav1n5QLjHAHitXFLGdOMBVdeF0elymw3YQSCpmILgkY4hRetAEaq16OLMZnX4o0RlOtAnGUhjblwqPqAMkpzJ4uhmGpZCgxeSuEbrWbuqN82j2xtrGM="
Feb 26 00:22:05 volumio go-librespot[32595]: time="2026-02-26T00:22:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:05 volumio go-librespot[32595]: time="2026-02-26T00:22:05-06:00" level=debug msg="completed keyexchange"
Feb 26 00:22:05 volumio go-librespot[32595]: time="2026-02-26T00:22:05-06:00" level=debug msg="completed challenge"
Feb 26 00:22:05 volumio go-librespot[32595]: time="2026-02-26T00:22:05-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 26 00:22:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:22:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:22:05 volumio volumio[32107]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 26 00:22:05 volumio volumio[32107]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 26 00:22:05 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 26 00:22:05 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 26 00:22:05 volumio volumio[32107]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 26 00:22:05 volumio volumio[32107]: info: MyVolumio login type: Token
Feb 26 00:22:05 volumio volumio[32107]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 26 00:22:05 volumio volumio[32107]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 26 00:22:06 volumio volumio[32107]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 26 00:22:06 volumio volumio[32107]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 26 00:22:06 volumio volumio[32107]: info: Streaming services startup
Feb 26 00:22:06 volumio volumio[32107]: info: Starting Streaming Daemon
Feb 26 00:22:06 volumio sudo[32603]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 26 00:22:06 volumio sudo[32603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 26 00:22:06 volumio volumio[32107]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 26 00:22:06 volumio sudo[32603]: pam_unix(sudo:session): session closed for user root
Feb 26 00:22:06 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:06 volumio volumio[32107]: error: Cannot start Volumio Streaming Daemon
Feb 26 00:22:06 volumio volumio[32107]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 26 00:22:06 volumio volumio[32107]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 26 00:22:06 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:06 volumio volumio[32107]: error: MyVolumio FAILED LOGIN: Invalid assertion format. 3 dot separated segments required.
Feb 26 00:22:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46.
Feb 26 00:22:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:08 volumio go-librespot[32610]: go-librespot daemon starting...
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=debug msg="app state loaded"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=info msg="zeroconf server listening on port 35553"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=debug msg="obtained new client token: AAAN9M3sfvCdS5Tf341KlhnY6WbsucztxTsXFPx6sKsKgCpjWbwC6FHx8dzo2+tq2c9HE2gdhndPmbsLYBdekeEQbHDyqkS5J5a5zQnZTyaP8BSgpYOv6XhiEi6G1GyI1OXixpP4X1CqbkpWWY647BbQXIA7n0hN8U3qdUbzmVmcT9ezzyPDt+dwM+ZTyBrAI5mTMWFv0x8p/DyBXgWcfU7T6Cq8EAALBXSyv2VL1keMLPJZTbESS9V/kQ=="
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=debug msg="completed keyexchange"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=debug msg="completed challenge"
Feb 26 00:22:08 volumio go-librespot[32611]: time="2026-02-26T00:22:08-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 26 00:22:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:22:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:22:09 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:09 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47.
Feb 26 00:22:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:12 volumio go-librespot[32618]: go-librespot daemon starting...
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=debug msg="app state loaded"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=info msg="zeroconf server listening on port 42735"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=debug msg="obtained new client token: AAAaIhgBBT2ofCaxT49HLMFKE3FnnGaoubu44ek3aDwPCxg88VlVPlh7LA6XvskXQsHDT68hEoQRfVxsKmby+uMx90sR/Nhl/aqEcoOzqdCpTVPJJzdpHc2gWUmndXis2q4qsw5uMfWcWJD30cUIpaOck2ia2keuflWQXLbg8Pgu2rfzgJDl6RANIOBNuDXcGn5KE4aV/E845OsNSI5d4iUqrx7iMDppd2KGPxxJZVHfpRWKGigc/WxCsA=="
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=debug msg="completed keyexchange"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=debug msg="completed challenge"
Feb 26 00:22:12 volumio go-librespot[32619]: time="2026-02-26T00:22:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 26 00:22:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:22:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:22:12 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:12 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:15 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:15 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48.
Feb 26 00:22:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:15 volumio go-librespot[32641]: go-librespot daemon starting...
Feb 26 00:22:15 volumio go-librespot[32642]: time="2026-02-26T00:22:15-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:15 volumio go-librespot[32642]: time="2026-02-26T00:22:15-06:00" level=debug msg="app state loaded"
Feb 26 00:22:15 volumio go-librespot[32642]: time="2026-02-26T00:22:15-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:16 volumio go-librespot[32642]: time="2026-02-26T00:22:16-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:16 volumio go-librespot[32642]: time="2026-02-26T00:22:16-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 26 00:22:16 volumio go-librespot[32642]: time="2026-02-26T00:22:16-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 26 00:22:16 volumio go-librespot[32642]: time="2026-02-26T00:22:16-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 26 00:22:16 volumio go-librespot[32642]: time="2026-02-26T00:22:16-06:00" level=info msg="zeroconf server listening on port 44931"
Feb 26 00:22:16 volumio go-librespot[32642]: time="2026-02-26T00:22:16-06:00" level=debug msg="obtained new client token: AADdvYbB9+rMNDk679NZrxICs4Oeonwtd5CZzFVOMk0WMbQs7vwQCG4H/gNGibHP3fJu8oHC9L3mTyHZuGwLaPYGKqfr8JKcCM4ICgFpZTcNes+bwkMNCUzy9VM5eKrbj8umI13ai/meQzOZbw06+L7ihdw4Kc1QXKZEwcWlRk675hg3SUzpGWYiVYqJXRMw8QAfariF5QLG8dkw44tb3cOZxpu3i14P7O0tU8plzVqbtkfCnSmyvG2sdg=="
Feb 26 00:22:16 volumio go-librespot[32642]: time="2026-02-26T00:22:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:16 volumio go-librespot[32642]: time="2026-02-26T00:22:16-06:00" level=debug msg="completed keyexchange"
Feb 26 00:22:16 volumio go-librespot[32642]: time="2026-02-26T00:22:16-06:00" level=debug msg="completed challenge"
Feb 26 00:22:16 volumio go-librespot[32642]: time="2026-02-26T00:22:16-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 26 00:22:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:22:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:22:18 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 26 00:22:18 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 26 00:22:18 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 26 00:22:18 volumio volumio-remote-updater[26837]: Test mode disabled
Feb 26 00:22:18 volumio volumio-remote-updater[26837]: Alpha mode disabled
Feb 26 00:22:18 volumio volumio-remote-updater[26837]: Alpha legacy test mode disabled
Feb 26 00:22:18 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 26 00:22:18 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:18 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:19 volumio volumio[32107]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\n- Fix for CPU utilization spike
\n- Fix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\n- Add BLE onboarding plugin
\n- Enable vc4-kms-v3d for all compatible RPi models
\n- Update Tidal SDK
\n
\n","title":"Update v4.096","updateavailable":true}
Feb 26 00:22:19 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 26 00:22:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49.
Feb 26 00:22:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:19 volumio go-librespot[32657]: go-librespot daemon starting...
Feb 26 00:22:19 volumio go-librespot[32658]: time="2026-02-26T00:22:19-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:19 volumio go-librespot[32658]: time="2026-02-26T00:22:19-06:00" level=debug msg="app state loaded"
Feb 26 00:22:19 volumio go-librespot[32658]: time="2026-02-26T00:22:19-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:19 volumio go-librespot[32658]: time="2026-02-26T00:22:19-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:19 volumio go-librespot[32658]: time="2026-02-26T00:22:19-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 26 00:22:19 volumio go-librespot[32658]: time="2026-02-26T00:22:19-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 26 00:22:19 volumio go-librespot[32658]: time="2026-02-26T00:22:19-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 26 00:22:19 volumio go-librespot[32658]: time="2026-02-26T00:22:19-06:00" level=info msg="zeroconf server listening on port 33563"
Feb 26 00:22:20 volumio go-librespot[32658]: time="2026-02-26T00:22:20-06:00" level=debug msg="obtained new client token: AAAd5IaQZgSaCAOm3+lU7zbGfHpjybB33aVf9qoEC/A/Fpygs1Vf7eoe4SxH8xjhspjxotB171NJKa7kEHSP/bTtKPuaWUysASvnO2vrtZ91TKAzZL57TEIUwDl361UZz9Tgmn02kswIBq8fITdX+7et5Ik3HDtZcXN2w6xUw3Yot9Sf6EpnzH3+o4EzwSChJS92Fj7Pjd2CfV4IxKi2gLjPY32dphDTPh3ASNe97vY8nlhD785U1bA="
Feb 26 00:22:20 volumio go-librespot[32658]: time="2026-02-26T00:22:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:20 volumio go-librespot[32658]: time="2026-02-26T00:22:20-06:00" level=debug msg="completed keyexchange"
Feb 26 00:22:20 volumio go-librespot[32658]: time="2026-02-26T00:22:20-06:00" level=debug msg="completed challenge"
Feb 26 00:22:20 volumio go-librespot[32658]: time="2026-02-26T00:22:20-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 26 00:22:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:22:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:22:20 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 26 00:22:20 volumio volumio[32107]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Feb 26 00:22:21 volumio volumio[32107]: info: CoreCommandRouter::volumioGetState
Feb 26 00:22:21 volumio volumio[32107]: info: CorePlayQueue::getTrack 0
Feb 26 00:22:21 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:21 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50.
Feb 26 00:22:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:23 volumio go-librespot[32665]: go-librespot daemon starting...
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=debug msg="app state loaded"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=info msg="zeroconf server listening on port 36827"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=debug msg="obtained new client token: AABcO9KStUVeJ2aH6E7dsE35j74mvAxvf3dP8ZbUlR7s1Mlq23xxGHOokFaygdG87hoYvfA4TuX+Mi5WvyvcuCM4ZrOQtESLRViX64XCas3M5ogpC/pugFtZrdRxAOmm7sbAX8l3Em4dk+sXS/07kGxNB7mTKMNEFcMDMNPHHd9xDZlRyvQXpn2BlW/5a2Mq8BGL1sWMMK3Y4wPNQ5mxjWSwPEh1Fq3uRlocF1lrJOZ+xKM3UGX4QtlLOw=="
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=debug msg="completed keyexchange"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=debug msg="completed challenge"
Feb 26 00:22:23 volumio go-librespot[32666]: time="2026-02-26T00:22:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 26 00:22:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:22:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:22:24 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:24 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:25 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 26 00:22:25 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 26 00:22:25 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Feb 26 00:22:25 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Feb 26 00:22:25 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Feb 26 00:22:25 volumio volumio[32107]: info: CoreCommandRouter::volumioGetBrowseSources
Feb 26 00:22:25 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 26 00:22:26 volumio volumio[32107]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Feb 26 00:22:26 volumio volumio[32107]: info: Completed starting MyVolumio Plugin
Feb 26 00:22:26 volumio volumio[32107]: [Metrics] CommandRouter: 54s 962.15ms
Feb 26 00:22:26 volumio volumio[32107]: info: CoreCommandRouter::volumiosetStartupVolume
Feb 26 00:22:26 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 26 00:22:26 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 26 00:22:26 volumio volumio[32107]: info: CoreCommandRouter::Close All Modals sent
Feb 26 00:22:26 volumio volumio[32107]: info: CoreCommandRouter::Close All Modals sent
Feb 26 00:22:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51.
Feb 26 00:22:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:27 volumio go-librespot[32690]: go-librespot daemon starting...
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=debug msg="app state loaded"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=info msg="zeroconf server listening on port 45525"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=debug msg="obtained new client token: AAAfKmp4N0yIzvbamfbbI3lupivRHOy4hlQO3YOgr7Neonkx3Jj9jeQc5/xQd+so1qu8xh8aSZi+NZmGfSYAJ0Du4qlystuHuZUqyiL/v9hCLApUiIvwOBasli803F0RTgxOv9ACZNNcFy1Cg4+742UCVVCl69/6jYAPGkRwAK+hKPCUzYIKcRRk/esH/++TvKHIWeADFgkNEY9UYfNkGiXX9vb2/olPQIsNhQK3+6AYhG1fmG9mtczAYw=="
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=debug msg="completed keyexchange"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=debug msg="completed challenge"
Feb 26 00:22:27 volumio go-librespot[32691]: time="2026-02-26T00:22:27-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 26 00:22:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:22:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:22:27 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Feb 26 00:22:27 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Feb 26 00:22:27 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Feb 26 00:22:27 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:27 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:30 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:30 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52.
Feb 26 00:22:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:30 volumio go-librespot[32701]: go-librespot daemon starting...
Feb 26 00:22:30 volumio go-librespot[32702]: time="2026-02-26T00:22:30-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:30 volumio go-librespot[32702]: time="2026-02-26T00:22:30-06:00" level=debug msg="app state loaded"
Feb 26 00:22:30 volumio go-librespot[32702]: time="2026-02-26T00:22:30-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:30 volumio go-librespot[32702]: time="2026-02-26T00:22:30-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:31 volumio go-librespot[32702]: time="2026-02-26T00:22:31-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 26 00:22:31 volumio go-librespot[32702]: time="2026-02-26T00:22:31-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 26 00:22:31 volumio go-librespot[32702]: time="2026-02-26T00:22:31-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 26 00:22:31 volumio go-librespot[32702]: time="2026-02-26T00:22:31-06:00" level=info msg="zeroconf server listening on port 35801"
Feb 26 00:22:31 volumio go-librespot[32702]: time="2026-02-26T00:22:31-06:00" level=debug msg="obtained new client token: AADfVTM9rfvAERFPAmhzJuIdQAV4oyX0RYZssBrsPfKvtnV7oUiy3T14mRiDvxd5xB6OOJoQT9+winnuHRv4CsqdIrtRTszPdJ3zPgx0fz+lc0cOsk9NExIgfQCqr/jQ7MeFQz/DIy7fIZlrCy6SA+c99kH0flDW0qOg534/fVbj5ZZ2tvVKOcVTL2/15QOFseC7G5Y6gfdGRuYDdVVRs+F54MymMHV79R0B6K+Ut1IYxwqgyq9q6DQiig=="
Feb 26 00:22:31 volumio go-librespot[32702]: time="2026-02-26T00:22:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:31 volumio go-librespot[32702]: time="2026-02-26T00:22:31-06:00" level=debug msg="completed keyexchange"
Feb 26 00:22:31 volumio go-librespot[32702]: time="2026-02-26T00:22:31-06:00" level=debug msg="completed challenge"
Feb 26 00:22:31 volumio go-librespot[32702]: time="2026-02-26T00:22:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 26 00:22:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:22:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:22:33 volumio volumio[32107]: info: BOOT COMPLETED
Feb 26 00:22:33 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:33 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53.
Feb 26 00:22:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:34 volumio go-librespot[32724]: go-librespot daemon starting...
Feb 26 00:22:34 volumio go-librespot[32725]: time="2026-02-26T00:22:34-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:34 volumio go-librespot[32725]: time="2026-02-26T00:22:34-06:00" level=debug msg="app state loaded"
Feb 26 00:22:34 volumio go-librespot[32725]: time="2026-02-26T00:22:34-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:34 volumio go-librespot[32725]: time="2026-02-26T00:22:34-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:35 volumio go-librespot[32725]: time="2026-02-26T00:22:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 26 00:22:35 volumio go-librespot[32725]: time="2026-02-26T00:22:35-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 26 00:22:35 volumio go-librespot[32725]: time="2026-02-26T00:22:35-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 26 00:22:35 volumio go-librespot[32725]: time="2026-02-26T00:22:35-06:00" level=info msg="zeroconf server listening on port 35553"
Feb 26 00:22:35 volumio go-librespot[32725]: time="2026-02-26T00:22:35-06:00" level=debug msg="obtained new client token: AAB6X3UC+jilVwZJZ3cOAgYaxi3pAawgbgDW2fruMZZ5qd+WV4XTBp9GbYYtNJNu54ClPmR7mKAlFi0d+uVaTD+6g9STP1jv4sOStZPI0Sjo3PqqCLjerfnqAq+ukih9zcnp91koHRJLXe6BBJGOfwRTvAemO2RV4vYczO3idYNKLRotdwSdSHcKL6XR5z1rCPnzWf0nwlAukifMDysBR6SXKZ3jRKnUw2xmHy1NpQLulV+7FZUQrvI="
Feb 26 00:22:35 volumio go-librespot[32725]: time="2026-02-26T00:22:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:35 volumio go-librespot[32725]: time="2026-02-26T00:22:35-06:00" level=debug msg="completed keyexchange"
Feb 26 00:22:35 volumio go-librespot[32725]: time="2026-02-26T00:22:35-06:00" level=debug msg="completed challenge"
Feb 26 00:22:35 volumio go-librespot[32725]: time="2026-02-26T00:22:35-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Feb 26 00:22:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:22:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:22:36 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:36 volumio volumio[32107]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 26 00:22:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54.
Feb 26 00:22:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 26 00:22:38 volumio go-librespot[32732]: go-librespot daemon starting...
Feb 26 00:22:38 volumio go-librespot[32733]: time="2026-02-26T00:22:38-06:00" level=info msg="running go-librespot 0.4.0"
Feb 26 00:22:38 volumio go-librespot[32733]: time="2026-02-26T00:22:38-06:00" level=debug msg="app state loaded"
Feb 26 00:22:38 volumio go-librespot[32733]: time="2026-02-26T00:22:38-06:00" level=debug msg="stored credentials not found"
Feb 26 00:22:38 volumio go-librespot[32733]: time="2026-02-26T00:22:38-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 26 00:22:39 volumio go-librespot[32733]: time="2026-02-26T00:22:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 26 00:22:39 volumio go-librespot[32733]: time="2026-02-26T00:22:39-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 26 00:22:39 volumio go-librespot[32733]: time="2026-02-26T00:22:39-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 26 00:22:39 volumio go-librespot[32733]: time="2026-02-26T00:22:39-06:00" level=info msg="zeroconf server listening on port 35279"
Feb 26 00:22:39 volumio go-librespot[32733]: time="2026-02-26T00:22:39-06:00" level=debug msg="obtained new client token: AAAGSapITrnryrTFnxEYlWYu1zwtghbTFMAwhibjdjYCdLR3a15mqwzaa5tRLf9p6vti/+lsnBoaRfdD0yRWWmGwcsPDX7CVqgYuMKs7cZr8C+AeCak3WnNEexQ4416GltAyVH3C3YYq7bvPopfBfFKijBcwfYQXJXKaDeRnD06XF1LfkjUN5X7I8+5DWc7yS8F5SgezfgCYhfz+uTOwBSROvDIiO8fVnLI+lj7wy3yu+3HBAEoMIKc="
Feb 26 00:22:39 volumio go-librespot[32733]: time="2026-02-26T00:22:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 26 00:22:39 volumio volumio[32107]: info: Initializing connection to go-librespot Websocket
Feb 26 00:22:39 volumio go-librespot[32733]: time="2026-02-26T00:22:39-06:00" level=debug msg="new websocket client"
Feb 26 00:22:39 volumio volumio[32107]: info: Connection to go-librespot Websocket established
Feb 26 00:22:42 volumio volumio[32107]: info: Getting Spotify volume
Feb 26 00:22:42 volumio volumio[32107]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Feb 26 00:22:43 volumio volumio[32107]: info: CoreCommandRouter::volumioGetState
Feb 26 00:22:43 volumio volumio[32107]: info: CorePlayQueue::getTrack 0
Feb 26 00:22:43 volumio volumio[32107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 26 00:22:43 volumio volumio[32107]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 26 00:22:43 volumio volumio[32107]: SPOTIFY: VOLUMIO VOLUME 100
Feb 26 00:22:43 volumio volumio[32107]: info: Aligning Spotify Volume to Volumio Volume
Feb 26 00:22:43 volumio volumio[32107]: info: CoreCommandRouter::volumioGetState
Feb 26 00:22:43 volumio volumio[32107]: info: CorePlayQueue::getTrack 0
Feb 26 00:22:43 volumio volumio[32107]: info: Setting Spotify Volume from Volumio: 100
Feb 26 00:22:44 volumio volumio[32107]: SPOTIFY: SETTING SPOTIFY VOLUME 100
Feb 26 00:22:44 volumio volumio[32107]: info: Sending Spotify command with payload to local API: /player/volume
Feb 26 00:22:48 volumio volumio[32107]: info: UPDATER: Scheduling automatic update
Feb 26 00:22:48 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime
Feb 26 00:22:48 volumio volumio[32107]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime
Feb 26 00:22:48 volumio volumio[32107]: info: UPDATER: Auto update will take place at: Fri Feb 27 2026 04:18:01 GMT-0600 (Central Standard Time)
Feb 26 00:23:25 volumio go-librespot[32733]: time="2026-02-26T00:23:25-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.221:45206->104.154.127.247:4070: read: connection reset by peer"
Feb 26 00:23:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 00:23:25 volumio volumio[32107]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up
Feb 26 00:23:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 26 00:23:25 volumio volumio[32107]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 26 00:23:25 volumio volumio[32107]: Error: socket hang up
Feb 26 00:23:25 volumio volumio[32107]: at connResetException (node:internal/errors:720:14)
Feb 26 00:23:25 volumio volumio[32107]: at Socket.socketOnEnd (node:_http_client:519:23)
Feb 26 00:23:25 volumio volumio[32107]: at Socket.emit (node:events:526:35)
Feb 26 00:23:25 volumio volumio[32107]: at endReadableNT (node:internal/streams/readable:1376:12)
Feb 26 00:23:25 volumio volumio[32107]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 26 00:23:25 volumio volumio[32107]: code: 'ECONNRESET',
Feb 26 00:23:25 volumio volumio[32107]: response: undefined
Feb 26 00:23:25 volumio volumio[32107]: }
Feb 26 00:23:25 volumio volumio[32107]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 26 00:23:26 volumio sudo[375]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 00:22'
Feb 26 00:23:26 volumio sudo[375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="ac7dd5922ede329d1459d48b226ddc71f5209a2c"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025"
VOLUMIO_VERSION="4.069"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"