Feb 12 03:58:00 volumio volumio[20689]: info: Initializing connection to go-librespot Websocket
Feb 12 03:58:00 volumio volumio[20689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:58:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74.
Feb 12 03:58:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:02 volumio go-librespot[21159]: go-librespot daemon starting...
Feb 12 03:58:02 volumio go-librespot[21160]: time="2026-02-12T03:58:02-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:02 volumio go-librespot[21160]: time="2026-02-12T03:58:02-06:00" level=debug msg="app state loaded"
Feb 12 03:58:02 volumio go-librespot[21160]: time="2026-02-12T03:58:02-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:02 volumio go-librespot[21160]: time="2026-02-12T03:58:02-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:02 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 03:58:03 volumio go-librespot[21160]: time="2026-02-12T03:58:03-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 12 03:58:03 volumio go-librespot[21160]: time="2026-02-12T03:58:03-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 12 03:58:03 volumio go-librespot[21160]: time="2026-02-12T03:58:03-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 12 03:58:03 volumio go-librespot[21160]: time="2026-02-12T03:58:03-06:00" level=info msg="zeroconf server listening on port 46085"
Feb 12 03:58:03 volumio go-librespot[21160]: time="2026-02-12T03:58:03-06:00" level=debug msg="obtained new client token: AABY6wedBEVNNXNxtbToije6LSSizm2E/eF/1Vq+ScF7jWIYeaiMCcj6OEfLMI3LjCEJsRWN6j+ehOUdh9FVMw9PUdHilN+YBCr+xSga3Ydoexo0ITdKwyuLMof8g3JefEc6RZIqN4JAZaXD83BzQSbdB6QM9tng1niXa2AA7a3sQxId0S4dGotkUOkcovY/JhzubvVAVy++vFKfOXqzSNFZGQ0bl2X9OcyR0AeduZd9s8y+m7js6fM="
Feb 12 03:58:03 volumio go-librespot[21160]: time="2026-02-12T03:58:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:03 volumio go-librespot[21160]: time="2026-02-12T03:58:03-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:03 volumio go-librespot[21160]: time="2026-02-12T03:58:03-06:00" level=debug msg="completed challenge"
Feb 12 03:58:03 volumio go-librespot[21160]: time="2026-02-12T03:58:03-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 12 03:58:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:03 volumio volumio[20689]: info: Initializing connection to go-librespot Websocket
Feb 12 03:58:05 volumio volumio[20689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:58:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75.
Feb 12 03:58:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:06 volumio go-librespot[21182]: go-librespot daemon starting...
Feb 12 03:58:06 volumio go-librespot[21183]: time="2026-02-12T03:58:06-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:06 volumio go-librespot[21183]: time="2026-02-12T03:58:06-06:00" level=debug msg="app state loaded"
Feb 12 03:58:06 volumio go-librespot[21183]: time="2026-02-12T03:58:06-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:06 volumio go-librespot[21183]: time="2026-02-12T03:58:06-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:06 volumio go-librespot[21183]: time="2026-02-12T03:58:06-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 12 03:58:06 volumio go-librespot[21183]: time="2026-02-12T03:58:06-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 12 03:58:06 volumio go-librespot[21183]: time="2026-02-12T03:58:06-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 12 03:58:06 volumio go-librespot[21183]: time="2026-02-12T03:58:06-06:00" level=info msg="zeroconf server listening on port 33721"
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 12 03:58:06 volumio volumio[20689]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 12 03:58:06 volumio volumio[20689]: info: Adding plugin multiroom to MyMusic Plugins
Feb 12 03:58:06 volumio volumio[20689]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 12 03:58:06 volumio volumio[20689]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 12 03:58:06 volumio volumio[20689]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 12 03:58:06 volumio volumio[20689]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 12 03:58:06 volumio volumio[20689]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 12 03:58:06 volumio volumio[20689]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 12 03:58:06 volumio go-librespot[21183]: time="2026-02-12T03:58:06-06:00" level=debug msg="obtained new client token: AABTDwkkf3LtAxy7yYIBnLuXriP76ti8yIGba1F6me1A2tKptTJ44PXNp15649JKo/wh84CA02dORdhkUx+nKVlpK37HHRpdo6+Z6bxTsnZ2ZlKg239oGBiWuIc+7wVBz9uvZ2wUYVG8ExULwN4dfvRP6wgfVI3cEFhNT6BHfQP8E/2K8PdRE7gQH8fJ/sw6muxV32we5A/KeJeZxaZRotyO8ENZO5nUyi3YhI2c2zTLebfdEjYLrxF7Rw=="
Feb 12 03:58:06 volumio go-librespot[21183]: time="2026-02-12T03:58:06-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Feb 12 03:58:07 volumio go-librespot[21183]: time="2026-02-12T03:58:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Feb 12 03:58:07 volumio go-librespot[21183]: time="2026-02-12T03:58:07-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:07 volumio go-librespot[21183]: time="2026-02-12T03:58:07-06:00" level=debug msg="completed challenge"
Feb 12 03:58:07 volumio go-librespot[21183]: time="2026-02-12T03:58:07-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 12 03:58:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:07 volumio volumio[20689]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 12 03:58:07 volumio volumio[20689]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 12 03:58:07 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:07 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:07 volumio volumio[20689]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 12 03:58:07 volumio volumio[20689]: info: MyVolumio login type: Token
Feb 12 03:58:07 volumio volumio[20689]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 12 03:58:07 volumio volumio[20689]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 12 03:58:08 volumio volumio[20689]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 12 03:58:08 volumio volumio[20689]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 12 03:58:08 volumio volumio[20689]: info: Streaming services startup
Feb 12 03:58:08 volumio volumio[20689]: info: Starting Streaming Daemon
Feb 12 03:58:08 volumio sudo[21192]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 03:58:08 volumio sudo[21192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:08 volumio volumio[20689]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 12 03:58:08 volumio sudo[21192]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:08 volumio volumio[20689]: info: Initializing connection to go-librespot Websocket
Feb 12 03:58:08 volumio volumio[20689]: error: Cannot start Volumio Streaming Daemon
Feb 12 03:58:08 volumio volumio[20689]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 12 03:58:08 volumio volumio[20689]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 12 03:58:08 volumio volumio[20689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:58:08 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 03:58:09 volumio volumio[20689]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 12 03:58:09 volumio volumio[20689]: info: MyVolumio token set successfully
Feb 12 03:58:09 volumio volumio[20689]: info: MYVOLUMIO: Adding device
Feb 12 03:58:09 volumio volumio[20689]: info: MYVOLUMIO: Evaluating Server
Feb 12 03:58:09 volumio volumio[20689]: info: MyVolumio status changed
Feb 12 03:58:09 volumio volumio[20689]: info: Streaming services startup
Feb 12 03:58:09 volumio volumio[20689]: info: Starting Streaming Daemon
Feb 12 03:58:09 volumio volumio[20689]: info: Removing browser output: myVolumio user plan is not superstar
Feb 12 03:58:09 volumio volumio[20689]: info: Removing audio output:
Feb 12 03:58:09 volumio volumio[20689]: info: Stoppping Tunnel 1
Feb 12 03:58:09 volumio sudo[21221]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 12 03:58:09 volumio sudo[21221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:09 volumio sudo[21223]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 12 03:58:09 volumio sudo[21223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 03:58:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 03:58:09 volumio sudo[21221]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:09 volumio volumio[20689]: error: Cannot start Volumio Streaming Daemon
Feb 12 03:58:09 volumio volumio[20689]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 12 03:58:09 volumio volumio[20689]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 12 03:58:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 03:58:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 03:58:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 03:58:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 03:58:09 volumio sudo[21223]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:09 volumio volumio[20689]: info: Remote SSH Stopped
Feb 12 03:58:09 volumio volumio[20689]: info: Setting Geolocation for MyVolumio to us1
Feb 12 03:58:09 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:09 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:09 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 76.
Feb 12 03:58:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:10 volumio go-librespot[21226]: go-librespot daemon starting...
Feb 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-06:00" level=debug msg="app state loaded"
Feb 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:10 volumio volumio[20689]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-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 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-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 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-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 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-06:00" level=info msg="zeroconf server listening on port 36329"
Feb 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-06:00" level=debug msg="obtained new client token: AABQ0KNg41h90Ej94An/WpRRVqvnlz8iOPFNqFcM1UXkXbgWPG0qz3GR8AlccLETExiBkRYLYGLEkA6tkMt0m712jI5Kt+12JMp/V4o0wyzQLxJz/ftWdkELJOf0Oi0nRigO4KFor7cIarC7NH/VVOK7ZyCk1eMzfepbAvpXwZXIe8abBC6qCYzbIjbGGHSvIGfHz/HWhj7xiZ4eKRqBAizxv0yIeJAUpoZ/6pU4BlWzY2fR31MeqxGyHw=="
Feb 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-06:00" level=debug msg="completed challenge"
Feb 12 03:58:10 volumio go-librespot[21227]: time="2026-02-12T03:58:10-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 12 03:58:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:10 volumio volumio[20689]: info: Updating MyVolumio device info
Feb 12 03:58:10 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:10 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:10 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:11 volumio volumio[20689]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 12 03:58:11 volumio volumio[20689]: info: Initializing connection to go-librespot Websocket
Feb 12 03:58:11 volumio volumio[20689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:58:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 77.
Feb 12 03:58:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:14 volumio go-librespot[21234]: go-librespot daemon starting...
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-06:00" level=debug msg="app state loaded"
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-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 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-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 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-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 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-06:00" level=info msg="zeroconf server listening on port 42127"
Feb 12 03:58:14 volumio volumio[20689]: info: MYVOLUMIO: Adding device
Feb 12 03:58:14 volumio volumio[20689]: info: MYVOLUMIO: Evaluating Server
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-06:00" level=debug msg="obtained new client token: AAAOyygeO2UN4EKAW4nIOCGggv6C0rTCn7npgpOsHZZzy4cu5EZkrMqzQRINp39yHCeHA28nYlVDp5+v2Kt5R5X6dDdvf8vjVt39VQQ/uk9aCLWJihmxHeMIYlslH05KLMqCU64Un2SXQDgmqBSOHvaXGEPNPwAWyMiF2HfsixUohw6JdXUuzDSDrUS+P7a44/QIJYuttN+pssYPmXLEOkLh4nGjoiSmilyAjzJ8nbb1MaY9YOtlPY1Vlw=="
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-06:00" level=debug msg="completed challenge"
Feb 12 03:58:14 volumio go-librespot[21235]: time="2026-02-12T03:58:14-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 12 03:58:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:14 volumio volumio[20689]: info: Initializing connection to go-librespot Websocket
Feb 12 03:58:14 volumio volumio[20689]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:58:16 volumio volumio[20689]: info: Setting Geolocation for MyVolumio to us1
Feb 12 03:58:16 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:16 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:16 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:16 volumio volumio[20689]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 12 03:58:17 volumio volumio[20689]: info: Updating MyVolumio device info
Feb 12 03:58:17 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:17 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:17 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 78.
Feb 12 03:58:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:17 volumio go-librespot[21274]: go-librespot daemon starting...
Feb 12 03:58:17 volumio go-librespot[21275]: time="2026-02-12T03:58:17-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:17 volumio go-librespot[21275]: time="2026-02-12T03:58:17-06:00" level=debug msg="app state loaded"
Feb 12 03:58:17 volumio go-librespot[21275]: time="2026-02-12T03:58:17-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:17 volumio go-librespot[21275]: time="2026-02-12T03:58:17-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:17 volumio volumio[20689]: info: Initializing connection to go-librespot Websocket
Feb 12 03:58:17 volumio go-librespot[21275]: time="2026-02-12T03:58:17-06:00" level=debug msg="new websocket client"
Feb 12 03:58:17 volumio volumio[20689]: info: Connection to go-librespot Websocket established
Feb 12 03:58:18 volumio go-librespot[21275]: time="2026-02-12T03:58:18-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 12 03:58:18 volumio go-librespot[21275]: time="2026-02-12T03:58:18-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 12 03:58:18 volumio go-librespot[21275]: time="2026-02-12T03:58:18-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 12 03:58:18 volumio go-librespot[21275]: time="2026-02-12T03:58:18-06:00" level=info msg="zeroconf server listening on port 45331"
Feb 12 03:58:18 volumio go-librespot[21275]: time="2026-02-12T03:58:18-06:00" level=debug msg="obtained new client token: AADRIm+V7+SLFApUufPBHLPiQjhh0Wngpnyrptumlyo35stS1dvKSNfKTsYXEQkL4GWZKlfArS2wPIbJ/P2W1A4eqheJfwa6aQ8RdqdBuLmnnRmIIG3nCHwQgK4A0jkrjjLBqB8iPhNZR9MqkwR4QccWTMJhFZBkrvFNJ3NWylCLX1Q1T2YY80tAW0MsK29qeo/6JO/5llVi7RDWLDy2/V+sgD/lvLlH61Ym6iUpNR3MpmkX2hACJrM="
Feb 12 03:58:18 volumio go-librespot[21275]: time="2026-02-12T03:58:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:18 volumio go-librespot[21275]: time="2026-02-12T03:58:18-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:18 volumio go-librespot[21275]: time="2026-02-12T03:58:18-06:00" level=debug msg="completed challenge"
Feb 12 03:58:18 volumio go-librespot[21275]: time="2026-02-12T03:58:18-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 12 03:58:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:18 volumio volumio[20689]: info: Connection to go-librespot Websocket closed
Feb 12 03:58:18 volumio volumio[20689]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 12 03:58:20 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 03:58:20 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:20 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 12 03:58:20 volumio volumio-remote-updater[2265]: Test mode disabled
Feb 12 03:58:20 volumio volumio-remote-updater[2265]: Alpha mode disabled
Feb 12 03:58:20 volumio volumio-remote-updater[2265]: Alpha legacy test mode disabled
Feb 12 03:58:20 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 12 03:58:20 volumio volumio[20689]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for CPU utilization spike
\nFix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\nAdd BLE onboarding plugin
\nEnable vc4-kms-v3d for all compatible RPi models
\nUpdate Tidal SDK
\n\n","title":"Update v4.096","updateavailable":true}
Feb 12 03:58:20 volumio volumio[20689]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 12 03:58:20 volumio volumio[20689]: info: Getting Spotify volume
Feb 12 03:58:20 volumio volumio[20689]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 03:58:20 volumio volumio[20689]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:58:20 volumio volumio[20689]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 12 03:58:20 volumio volumio[20689]:   errno: -111,
Feb 12 03:58:20 volumio volumio[20689]:   code: 'ECONNREFUSED',
Feb 12 03:58:20 volumio volumio[20689]:   syscall: 'connect',
Feb 12 03:58:20 volumio volumio[20689]:   address: '127.0.0.1',
Feb 12 03:58:20 volumio volumio[20689]:   port: 9879,
Feb 12 03:58:20 volumio volumio[20689]:   response: undefined
Feb 12 03:58:20 volumio volumio[20689]: }
Feb 12 03:58:20 volumio volumio[20689]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 03:58:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 79.
Feb 12 03:58:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:21 volumio go-librespot[21301]: go-librespot daemon starting...
Feb 12 03:58:21 volumio go-librespot[21302]: time="2026-02-12T03:58:21-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:21 volumio go-librespot[21302]: time="2026-02-12T03:58:21-06:00" level=debug msg="app state loaded"
Feb 12 03:58:21 volumio go-librespot[21302]: time="2026-02-12T03:58:21-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:21 volumio go-librespot[21302]: time="2026-02-12T03:58:21-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:21 volumio sudo[21310]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 03:57'
Feb 12 03:58:21 volumio sudo[21310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:21 volumio sudo[21310]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:21 volumio go-librespot[21302]: time="2026-02-12T03:58:21-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 12 03:58:21 volumio go-librespot[21302]: time="2026-02-12T03:58:21-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 12 03:58:21 volumio go-librespot[21302]: time="2026-02-12T03:58:21-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 12 03:58:21 volumio go-librespot[21302]: time="2026-02-12T03:58:21-06:00" level=info msg="zeroconf server listening on port 33081"
Feb 12 03:58:22 volumio volumio-remote-updater[2265]: [2026-02-12 03:58:22] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 12 03:58:22 volumio volumio-remote-updater[2265]: [2026-02-12 03:58:22] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 12 03:58:22 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:22 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 12 03:58:22 volumio systemd[1]: volumio.service: Consumed 52.058s CPU time.
Feb 12 03:58:22 volumio go-librespot[21302]: time="2026-02-12T03:58:22-06:00" level=debug msg="obtained new client token: AADmXXDrnNojkhgf/e+F+4IgAV49eR+bJYHOtQ4WvaAkqn5BjeG4WAS0NMlwgXUqZHLaBMpK8Oo2Z3vVMNz+R1ODMN6UhorT8p+aSY/Ssj39AuNrI/hWlauRW3UA90HhOP2gvtTR1zYRrs9qgInx4Q/KamUSvp+UzrA9eI+ra71CHdb03FLchwsWYEaX+1SXWfYPADT/uuR1xLohaGf7P6f3h65dxLxwTJcnlj6fqw5feFn1GVUI0V8="
Feb 12 03:58:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 03:58:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 03:58:22 volumio go-librespot[21302]: time="2026-02-12T03:58:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:22 volumio go-librespot[21302]: time="2026-02-12T03:58:22-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:22 volumio go-librespot[21302]: time="2026-02-12T03:58:22-06:00" level=debug msg="completed challenge"
Feb 12 03:58:22 volumio go-librespot[21302]: time="2026-02-12T03:58:22-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 12 03:58:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:22 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6154.
Feb 12 03:58:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 03:58:22 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 12 03:58:22 volumio systemd[1]: volumio.service: Consumed 52.058s CPU time.
Feb 12 03:58:22 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 12 03:58:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 03:58:24 volumio volumio[21326]: info: -------------------------------------------
Feb 12 03:58:24 volumio volumio[21326]: info: -----            Volumio3              ----
Feb 12 03:58:24 volumio volumio[21326]: info: -------------------------------------------
Feb 12 03:58:24 volumio volumio[21326]: info: -----          System startup          ----
Feb 12 03:58:24 volumio volumio[21326]: info: -------------------------------------------
Feb 12 03:58:25 volumio volumio[21326]: info: MYVOLUMIO Environment detected
Feb 12 03:58:25 volumio volumio[21326]: info: Plugin folders cleanup
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning into folder /volumio/app/plugins/
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category audio_interface
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category miscellanea
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category music_service
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category plugins.json
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category system_controller
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category user_interface
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning into folder /data/plugins/
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category audio_interface
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category music_service
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category system_controller
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category system_hardware
Feb 12 03:58:25 volumio volumio[21326]: info: Scanning category user_interface
Feb 12 03:58:25 volumio volumio[21326]: info: Plugin folders cleanup completed
Feb 12 03:58:25 volumio volumio[21326]: info: -------------------------------------------
Feb 12 03:58:25 volumio volumio[21326]: info: -----      Core plugins startup        ----
Feb 12 03:58:25 volumio volumio[21326]: info: -------------------------------------------
Feb 12 03:58:25 volumio volumio[21326]: info: Loading plugins from folder /volumio/app/plugins/
Feb 12 03:58:25 volumio volumio[21326]: info: Adding plugin upnp to MyMusic Plugins
Feb 12 03:58:25 volumio volumio[21326]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 12 03:58:25 volumio volumio[21326]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 12 03:58:25 volumio volumio[21326]: info: Loading plugins from folder /data/plugins/
Feb 12 03:58:25 volumio volumio[21326]: info: Loading plugin "system"...
Feb 12 03:58:25 volumio volumio[21326]: info: Loading plugin "appearance"...
Feb 12 03:58:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 80.
Feb 12 03:58:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:25 volumio go-librespot[21353]: go-librespot daemon starting...
Feb 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-06:00" level=debug msg="app state loaded"
Feb 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-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 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-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 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-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 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-06:00" level=info msg="zeroconf server listening on port 34639"
Feb 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-06:00" level=debug msg="obtained new client token: AABEtzUgysxgXruAycN03Dd3woFGYmd9RqxDKWlqRA/cTeN9b8p8nQrAL74orB548lj6TOvnM+TXA0RMYlyYQAJ/Mn7b9a0wBSMVydiKeUVKK3ImpdmHnGWCxrtDNnL16WxnYv29ZiEjb8/YXGbkrTaGPORE+87wBMCYurg41g+3e0x58xXdnGEwlLzdj8kL9BWehPUEh3Jyw4xiZzWvudcT27zzHqGrrH4zYHs3OF8L/wd6/6ga1ojldw=="
Feb 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-06:00" level=debug msg="completed challenge"
Feb 12 03:58:25 volumio go-librespot[21354]: time="2026-02-12T03:58:25-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 12 03:58:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:26 volumio volumio[21326]: info: Loading plugin "network"...
Feb 12 03:58:26 volumio volumio[21326]: info: Refreshing Cached IP Addresses
Feb 12 03:58:26 volumio sudo[21362]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 03:58:26 volumio sudo[21362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:26 volumio sudo[21362]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:26 volumio sudo[21364]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 03:58:26 volumio sudo[21364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:26 volumio sudo[21364]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:26 volumio volumio[21326]: info: Loading plugin "services"...
Feb 12 03:58:26 volumio volumio[21326]: info: Loading plugin "alsa_controller"...
Feb 12 03:58:26 volumio sudo[21375]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 12 03:58:26 volumio sudo[21375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:26 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 03:58:26 volumio volumio[21326]: info: Loading plugin "wizard"...
Feb 12 03:58:26 volumio volumio[21326]: info: Loading plugin "networkfs"...
Feb 12 03:58:26 volumio volumio[21326]: info: Starting Udev Watcher for removable devices
Feb 12 03:58:26 volumio volumio[21326]: info: Ignoring mount for partition: boot
Feb 12 03:58:26 volumio volumio[21326]: info: Ignoring mount for partition: volumio
Feb 12 03:58:26 volumio volumio[21326]: info: Ignoring mount for partition: volumio_data
Feb 12 03:58:26 volumio volumio[21326]: info: Mounting Device Wikipedia
Feb 12 03:58:26 volumio sudo[21401]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Feb 12 03:58:26 volumio sudo[21401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:26 volumio sudo[21401]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:26 volumio volumio[21326]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 03:58:26 volumio volumio[21326]:        dmesg(1) may have more information after failed mount system call.
Feb 12 03:58:26 volumio volumio[21326]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Feb 12 03:58:26 volumio volumio[21326]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 03:58:26 volumio volumio[21326]:        dmesg(1) may have more information after failed mount system call.
Feb 12 03:58:26 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 03:58:26 volumio volumio[21326]: info: Loading plugin "volumio_command_line_client"...
Feb 12 03:58:26 volumio volumio[21326]: info: Loading plugin "upnp"...
Feb 12 03:58:26 volumio volumio[21326]: info: [1770890306751] Starting Upmpd Daemon
Feb 12 03:58:26 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 03:58:26 volumio volumio[21326]: info: Loading plugin "my_music"...
Feb 12 03:58:26 volumio volumio[21326]: info: Loading plugin "mpd"...
Feb 12 03:58:26 volumio sudo[21375]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:27 volumio volumio-remote-updater[2265]: [2026-02-12 03:58:27] [connect] Successful connection
Feb 12 03:58:27 volumio volumio[21326]: info: Loading plugin "upnp_browser"...
Feb 12 03:58:27 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 03:58:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 81.
Feb 12 03:58:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:29 volumio go-librespot[21405]: go-librespot daemon starting...
Feb 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-06:00" level=debug msg="app state loaded"
Feb 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-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 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-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 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-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 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-06:00" level=info msg="zeroconf server listening on port 37049"
Feb 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-06:00" level=debug msg="obtained new client token: AAB4EqtrFzHXIlux+C+SFsunapnz3PzWSBhhbvs/HrD0rpIqDUBGAsPlVuyGOahzt/PXDkkBTbszqh3shDqnVcjQDqJnjnRkZN+SESbu4Fc6yxuVO0C6wOvfydeFbU37ZdR9A2o+63Ssp2WzUjw88uABS8Y5SAGcnL6JbjqUEx/isqlabUdICW61uvs64SdlsTyaVB7j1qUO3kxb851nVJlw5u/8onnxF6PmvhKc167OXQA0Q9UCoz0dGg=="
Feb 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-06:00" level=debug msg="completed challenge"
Feb 12 03:58:29 volumio go-librespot[21406]: time="2026-02-12T03:58:29-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 12 03:58:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:30 volumio volumio[21326]: info: Loading plugin "alarm-clock"...
Feb 12 03:58:30 volumio volumio[21326]: info: Loading plugin "airplay_emulation"...
Feb 12 03:58:30 volumio volumio[21326]: info: Starting Shairport Sync
Feb 12 03:58:30 volumio volumio[21326]: info: Loading plugin "last_100"...
Feb 12 03:58:30 volumio volumio[21326]: info: Loading plugin "webradio"...
Feb 12 03:58:30 volumio volumio[21326]: info: Loading plugin "i2s_dacs"...
Feb 12 03:58:30 volumio volumio[21326]: info: I2S DAC not set, start Auto-detection
Feb 12 03:58:30 volumio volumio[21326]: info: Loading plugin "volumiodiscovery"...
Feb 12 03:58:30 volumio volumio[21326]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 03:58:30 volumio volumio[21326]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 03:58:30 volumio volumio[21326]: *** WARNING *** For more information see 
Feb 12 03:58:30 volumio volumio[21326]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 03:58:30 volumio volumio[21326]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 03:58:30 volumio volumio[21326]: *** WARNING *** For more information see 
Feb 12 03:58:30 volumio node[21326]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 03:58:30 volumio node[21326]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 03:58:30 volumio node[21326]: *** WARNING *** For more information see 
Feb 12 03:58:30 volumio node[21326]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 03:58:30 volumio node[21326]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 03:58:30 volumio node[21326]: *** WARNING *** For more information see 
Feb 12 03:58:30 volumio volumio[21326]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 12 03:58:30 volumio volumio[21326]: info: Discovery: Started advertising with name: Volumio
Feb 12 03:58:30 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 03:58:30 volumio volumio[21326]: info: Loading plugin "bandcamp"...
Feb 12 03:58:31 volumio volumio[21326]: info: Plugin calmradio is not enabled
Feb 12 03:58:31 volumio volumio[21326]: info: Loading plugin "soundcloud"...
Feb 12 03:58:32 volumio volumio[21326]: info: Loading plugin "spop"...
Feb 12 03:58:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 82.
Feb 12 03:58:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:33 volumio volumio[21326]: info: Loading plugin "squeezelite_mc"...
Feb 12 03:58:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:33 volumio go-librespot[21415]: go-librespot daemon starting...
Feb 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-06:00" level=debug msg="app state loaded"
Feb 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-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 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-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 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-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 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-06:00" level=info msg="zeroconf server listening on port 42479"
Feb 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-06:00" level=debug msg="obtained new client token: AACFKNtZi/dJuHV1aEK0xEorcIeYaxBy4aYx/2P1QJUzKYvPy0A20GJUfzxvi4CebZ2EHlKKFLx1q82QfZmqLqyIetYJ5qvG5DTLYoKj+pQOCeC1aWAXzYi91x8F+E9mMeZGecxU63UYQQqZmvHY88eVXb+EWZOPDaAhoGoJXppG/kBHt+PsqgGcX/QrwjcQ6He89CQK1kteDGLVbmjYA3bGRfu1okV99M1aaDpTR56/adhPWLQI9lrnrA=="
Feb 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-06:00" level=debug msg="completed challenge"
Feb 12 03:58:33 volumio go-librespot[21416]: time="2026-02-12T03:58:33-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 12 03:58:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:33 volumio volumio[21326]: info: Loading plugin "youtube2"...
Feb 12 03:58:33 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 03:58:34 volumio volumio[21326]: info: Loading plugin "ytcr"...
Feb 12 03:58:35 volumio volumio[21326]: info: Loading plugin "ytmusic"...
Feb 12 03:58:36 volumio volumio[21326]: info: Plugin now_playing is not enabled
Feb 12 03:58:36 volumio volumio[21326]: info: Loading plugin "outputs"...
Feb 12 03:58:36 volumio volumio[21326]: info: Loading plugin "albumart"...
Feb 12 03:58:36 volumio volumio[21326]: info: Plugin example_plugin is not enabled
Feb 12 03:58:36 volumio volumio[21326]: info: Loading plugin "inputs"...
Feb 12 03:58:36 volumio volumio[21326]: info: Loading plugin "updater_comm"...
Feb 12 03:58:36 volumio volumio[21326]: info: Plugin mpdemulation is not enabled
Feb 12 03:58:36 volumio volumio[21326]: info: Loading plugin "rest_api"...
Feb 12 03:58:36 volumio volumio[21326]: info: Loading plugin "websocket"...
Feb 12 03:58:36 volumio volumio[21326]: info: Starting Socket.io Server version 1.7.4
Feb 12 03:58:36 volumio volumio[21326]: info: Plugin fusiondsp is not enabled
Feb 12 03:58:36 volumio volumio[21326]: info: Plugin mpdoutput is not enabled
Feb 12 03:58:36 volumio volumio[21326]: info: Plugin RoonBridge is not enabled
Feb 12 03:58:36 volumio volumio[21326]: info: Loading plugin "podcast"...
Feb 12 03:58:36 volumio volumio[21326]: info: ControllerPodcast::constructor
Feb 12 03:58:36 volumio volumio[21326]: info: Loading plugin "volusonic"...
Feb 12 03:58:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 83.
Feb 12 03:58:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:36 volumio go-librespot[21448]: go-librespot daemon starting...
Feb 12 03:58:36 volumio volumio[21424]: Forking 3 albumart workers
Feb 12 03:58:36 volumio go-librespot[21449]: time="2026-02-12T03:58:36-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:36 volumio go-librespot[21449]: time="2026-02-12T03:58:36-06:00" level=debug msg="app state loaded"
Feb 12 03:58:36 volumio go-librespot[21449]: time="2026-02-12T03:58:36-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:36 volumio go-librespot[21449]: time="2026-02-12T03:58:36-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:37 volumio go-librespot[21449]: time="2026-02-12T03:58:37-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 12 03:58:37 volumio go-librespot[21449]: time="2026-02-12T03:58:37-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 12 03:58:37 volumio go-librespot[21449]: time="2026-02-12T03:58:37-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 12 03:58:37 volumio go-librespot[21449]: time="2026-02-12T03:58:37-06:00" level=info msg="zeroconf server listening on port 43051"
Feb 12 03:58:37 volumio go-librespot[21449]: time="2026-02-12T03:58:37-06:00" level=debug msg="obtained new client token: AACi+SomiED8QWAptyYmTvTfVZs/NFa3IUpeBE2D6/0/x+7zVnag19d8mHnO8URa9Az8kpgfGr8XSGfwBJFF463V2ti9xUCZyYLa36EIwGX1nEH6q+9sH3BZ8eE3BZKdK3s8FJzP/7sDIKqofO98oM8N5/wU22hi2Cq1KwfCN4jiVG/Yjn9x+kryI7we1Kxqjn+eB0yQc/vkXP3DKboZYN1y/FGyRdXBvSSEs5l5xmyhn0LoPouTMEAthA=="
Feb 12 03:58:37 volumio go-librespot[21449]: time="2026-02-12T03:58:37-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:37 volumio go-librespot[21449]: time="2026-02-12T03:58:37-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:37 volumio go-librespot[21449]: time="2026-02-12T03:58:37-06:00" level=debug msg="completed challenge"
Feb 12 03:58:37 volumio go-librespot[21449]: time="2026-02-12T03:58:37-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 12 03:58:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:38 volumio volumio[21455]: Starting albumart workers
Feb 12 03:58:38 volumio volumio[21326]: info: Applying required configuration parameters for plugin volusonic
Feb 12 03:58:38 volumio volumio[21326]: info: Loading plugin "backup_restore"...
Feb 12 03:58:38 volumio volumio[21326]: info: Applying required configuration parameters for plugin backup_restore
Feb 12 03:58:38 volumio volumio[21456]: Starting albumart workers
Feb 12 03:58:38 volumio volumio[21326]: info: Plugin rpi_eeprom_config is not enabled
Feb 12 03:58:38 volumio volumio[21326]: info: Plugin rpi_eeprom_updater is not enabled
Feb 12 03:58:38 volumio volumio[21326]: info: Loading plugin "scheduledrestart"...
Feb 12 03:58:38 volumio volumio[21457]: Starting albumart workers
Feb 12 03:58:38 volumio volumio[21326]: info: Applying required configuration parameters for plugin scheduledrestart
Feb 12 03:58:38 volumio volumio[21326]: info: Plugin Bluetoothremote is not enabled
Feb 12 03:58:38 volumio volumio[21326]: info: Plugin music_services_shield is not enabled
Feb 12 03:58:38 volumio volumio[21326]: info: Loading plugin "Systeminfo"...
Feb 12 03:58:39 volumio volumio-remote-updater[2265]: [2026-02-12 03:58:39] [connect] Successful connection
Feb 12 03:58:39 volumio volumio[21326]: info: Plugin peppymeterbasic is not enabled
Feb 12 03:58:39 volumio volumio[21326]: info: Loading plugin "peppyspectrum"...
Feb 12 03:58:40 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 03:58:40 volumio volumio[21326]: info: Loading i18n strings for locale en
Feb 12 03:58:40 volumio volumio[21326]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 03:58:40 volumio volumio[21326]: Updating browse sources language
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 84.
Feb 12 03:58:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::initPlayerControls
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 03:58:40 volumio volumio[21326]: Express server listening on port 3000
Feb 12 03:58:40 volumio volumio[21326]:  [Metrics]  WebUI:  16s 836.96ms 
Feb 12 03:58:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:40 volumio go-librespot[21509]: go-librespot daemon starting...
Feb 12 03:58:40 volumio volumio[21326]: info: CoreStateMachine::resetVolumioState
Feb 12 03:58:40 volumio volumio[21326]: info: CoreStateMachine::getcurrentVolume
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 03:58:40 volumio go-librespot[21511]: time="2026-02-12T03:58:40-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:40 volumio go-librespot[21511]: time="2026-02-12T03:58:40-06:00" level=debug msg="app state loaded"
Feb 12 03:58:40 volumio go-librespot[21511]: time="2026-02-12T03:58:40-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:40 volumio go-librespot[21511]: time="2026-02-12T03:58:40-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:40 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:40 volumio sudo[21522]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 03:58:40 volumio sudo[21522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:40 volumio sudo[21522]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:40 volumio sudo[21524]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 03:58:40 volumio sudo[21524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:40 volumio volumio[21326]: info: Volumio Network Manager: Network status updated: 1
Feb 12 03:58:40 volumio sudo[21524]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:41 volumio volumio[21326]: info: VolumeController:: Volume=100 Mute =false
Feb 12 03:58:41 volumio volumio[21326]: info: CoreStateMachine::pushState
Feb 12 03:58:41 volumio volumio[21326]: info: CorePlayQueue::getTrack 0
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::volumioPushState
Feb 12 03:58:41 volumio volumio[21326]: info: CoreStateMachine::updateTrackBlock
Feb 12 03:58:41 volumio volumio[21326]: info: CorePlayQueue::getTrackBlock
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 03:58:41 volumio go-librespot[21511]: time="2026-02-12T03:58:41-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 12 03:58:41 volumio go-librespot[21511]: time="2026-02-12T03:58:41-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 12 03:58:41 volumio go-librespot[21511]: time="2026-02-12T03:58:41-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 12 03:58:41 volumio volumio-remote-updater[2265]: [2026-02-12 03:58:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770890319 101
Feb 12 03:58:41 volumio go-librespot[21511]: time="2026-02-12T03:58:41-06:00" level=info msg="zeroconf server listening on port 33011"
Feb 12 03:58:41 volumio volumio[21326]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1
Feb 12 03:58:41 volumio volumio[21326]: info: Reloading queue from file
Feb 12 03:58:41 volumio volumio[21326]: info: CoreStateMachine::setRepeat null single undefined
Feb 12 03:58:41 volumio volumio[21326]: info: CoreStateMachine::pushState
Feb 12 03:58:41 volumio volumio[21326]: info: CorePlayQueue::getTrack 0
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::volumioPushState
Feb 12 03:58:41 volumio volumio[21326]: info: CoreStateMachine::setRandom null
Feb 12 03:58:41 volumio volumio[21326]: info: CoreStateMachine::pushState
Feb 12 03:58:41 volumio volumio[21326]: info: CorePlayQueue::getTrack 0
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::volumioPushState
Feb 12 03:58:41 volumio volumio[21326]: info: Setting Device type: Raspberry PI
Feb 12 03:58:41 volumio go-librespot[21511]: time="2026-02-12T03:58:41-06:00" level=debug msg="obtained new client token: AAC5Zq+UFllU7ieH7wipDd7WZjbMUXVPZre4iO/VcMBeaz+9vibQLJbmqDjcsRKA4OfV6XnCpMhmsxQLDFzaDByxAT8SrTIWfP65qlFezt4hFdAGfkXUFfYHfZhbZgHylAwUQTIiJ74IhBpxX2SwlFMTURVK0LvlGS3VfGHZoS75JiVKwOM6aSpB50izBefYznGckwuGXs7FE7vN1OxMqoqPyScuQNrCdqiITYg/rQHd2V/nQlCtUYk="
Feb 12 03:58:41 volumio volumio[21326]: info: VolumeController:: Volume=100 Mute =false
Feb 12 03:58:41 volumio volumio[21326]: info: CoreStateMachine::pushState
Feb 12 03:58:41 volumio volumio[21326]: info: CorePlayQueue::getTrack 0
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::volumioPushState
Feb 12 03:58:41 volumio go-librespot[21511]: time="2026-02-12T03:58:41-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:41 volumio volumio[21326]: info: Completed loading Core Plugins
Feb 12 03:58:41 volumio volumio[21326]: info: Preparing to generate the ALSA configuration file
Feb 12 03:58:41 volumio sudo[21539]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 12 03:58:41 volumio sudo[21539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:41 volumio go-librespot[21511]: time="2026-02-12T03:58:41-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:41 volumio go-librespot[21511]: time="2026-02-12T03:58:41-06:00" level=debug msg="completed challenge"
Feb 12 03:58:41 volumio volumio[21326]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 03:58:41 volumio volumio[21326]: info: Reading ALSA contributions from plugins.
Feb 12 03:58:41 volumio volumio[21326]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 03:58:41 volumio volumio[21326]: info: Output device has changed, restarting MPD
Feb 12 03:58:41 volumio go-librespot[21511]: time="2026-02-12T03:58:41-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 12 03:58:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:41 volumio volumio[21326]: info: Output device has changed, restarting Shairport Sync
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:41 volumio sudo[21542]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 03:58:41 volumio sudo[21542]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:41 volumio sudo[21544]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 03:58:41 volumio sudo[21544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:41 volumio sudo[21542]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:41 volumio sudo[21539]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:41 volumio volumio[21326]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 03:58:41 volumio volumio[21326]: info: ___________ START PLUGINS ___________
Feb 12 03:58:41 volumio volumio[21326]: info: ControllerMpd::onStart: Initializing MPD
Feb 12 03:58:41 volumio volumio[21326]: info: Creating MPD Configuration file
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:58:41 volumio volumio[21326]: info: [1770890321642] CoreMusicLibrary::Adding element Media Servers
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 12 03:58:41 volumio sudo[21552]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 03:58:41 volumio sudo[21552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:41 volumio sudo[21554]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:41 volumio sudo[21554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:41 volumio sudo[21552]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:41 volumio volumio[21326]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:41 volumio volumio[21326]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 03:58:41 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 03:58:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 03:58:41 volumio systemd[1]: mpd.service: Consumed 4.493s CPU time.
Feb 12 03:58:41 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 03:58:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 03:58:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:58:41 volumio volumio[21326]: info: [1770890321845] CoreMusicLibrary::Adding element Last_100
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:58:41 volumio volumio[21326]: info: [1770890321854] CoreMusicLibrary::Adding element Webradio
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 03:58:41 volumio volumio[21326]: info: Initializing BBC Radios
Feb 12 03:58:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 03:58:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:58:41 volumio volumio[21326]: info: [1770890321989] CoreMusicLibrary::Adding element Bandcamp Discover
Feb 12 03:58:41 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:41 volumio volumio[21326]: Cannot find translation for source Bandcamp Discover
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:58:42 volumio volumio[21326]: info: [1770890322009] CoreMusicLibrary::Adding element SoundCloud
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Bandcamp Discover
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source SoundCloud
Feb 12 03:58:42 volumio volumio[21326]: info: Creating Spotify config file
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:42 volumio sudo[21571]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 03:58:42 volumio sudo[21571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 03:58:42 volumio sudo[21571]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:42 volumio volumio[21326]: info: [squeezelite_mc] Starting proxy server...
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:58:42 volumio volumio[21326]: info: [1770890322479] CoreMusicLibrary::Adding element YouTube2
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Bandcamp Discover
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source SoundCloud
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube2
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:58:42 volumio volumio[21326]: info: [1770890322498] CoreMusicLibrary::Adding element YouTube Music
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Bandcamp Discover
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source SoundCloud
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube2
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube Music
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:58:42 volumio volumio[21326]: info: [1770890322509] CoreMusicLibrary::Adding element Podcast
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Bandcamp Discover
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source SoundCloud
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube2
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube Music
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Podcast
Feb 12 03:58:42 volumio volumio[21326]: info: Loading i18n strings for locale en
Feb 12 03:58:42 volumio volumio[21326]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 03:58:42 volumio volumio[21326]: Updating browse sources language
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Bandcamp Discover
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source SoundCloud
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube2
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube Music
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Podcast
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Bandcamp Discover
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source SoundCloud
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube2
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube Music
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Podcast
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:58:42 volumio volumio[21326]: info: [1770890322565] CoreMusicLibrary::Adding element Volusonic
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Bandcamp Discover
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source SoundCloud
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube2
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source YouTube Music
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Podcast
Feb 12 03:58:42 volumio volumio[21326]: Cannot find translation for source Volusonic
Feb 12 03:58:42 volumio volumio[21326]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Feb 12 03:58:42 volumio volumio[21326]: info: Volumio Calling Home
Feb 12 03:58:42 volumio volumio[21326]: info: [squeezelite_mc] Proxy server started on port 33807
Feb 12 03:58:42 volumio volumio[21326]: info: Preparing to generate the ALSA configuration file
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 03:58:42 volumio volumio[21326]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 03:58:42 volumio volumio[21326]: info: Discovery: Found device Volumio
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::volumioGetState
Feb 12 03:58:42 volumio volumio[21326]: info: CorePlayQueue::getTrack 0
Feb 12 03:58:42 volumio volumio[21326]: info: Discovery: this is already registered,  a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 03:58:42 volumio volumio[21326]: info: Discovery: Found device Volumio
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::volumioGetState
Feb 12 03:58:42 volumio volumio[21326]: info: CorePlayQueue::getTrack 0
Feb 12 03:58:42 volumio volumio[21326]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 03:58:42 volumio volumio[21326]: info: Reading ALSA contributions from plugins.
Feb 12 03:58:42 volumio volumio[21326]: info: MPD Permissions set
Feb 12 03:58:42 volumio volumio[21326]: info: MPD Permissions set
Feb 12 03:58:42 volumio volumio[21326]: info: Upmpdcli Daemon Started
Feb 12 03:58:42 volumio volumio[21326]: info: Spotify config file written
Feb 12 03:58:42 volumio volumio[21326]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 12 03:58:42 volumio sudo[21588]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 12 03:58:42 volumio sudo[21588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:42 volumio volumio[21326]: info: VolumeController:: Volume=100 Mute =false
Feb 12 03:58:42 volumio volumio[21326]: info: CoreStateMachine::pushState
Feb 12 03:58:42 volumio volumio[21326]: info: CorePlayQueue::getTrack 0
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::volumioPushState
Feb 12 03:58:42 volumio volumio[21326]: info: [squeezelite_mc] Server discovery started
Feb 12 03:58:42 volumio volumio[21326]: info: [squeezelite_mc] Player finder started
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:42 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 03:58:42 volumio volumio[21326]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero  2>&1 || true
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: No need to fix Spotify hosts
Feb 12 03:58:43 volumio go-librespot[21594]: go-librespot daemon starting...
Feb 12 03:58:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:43 volumio sudo[21588]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-06:00" level=debug msg="app state loaded"
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:43 volumio volumio[21326]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Feb 12 03:58:43 volumio volumio[21326]: info: Volumio called home
Feb 12 03:58:43 volumio volumio[21326]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Feb 12 03:58:43 volumio volumio[21326]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Feb 12 03:58:43 volumio volumio[21326]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Feb 12 03:58:43 volumio volumio[21326]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 03:58:43 volumio volumio[21326]: SPOTIFY: BQD9UhZQ6wOBwUe3DREe5Abhi8b53LLCvzpyjx-ayUynFT0kjN23PZSVKeDWzsCq3lldYllyKjKzjy_jCcsgILJOp2-9yFodkEyo0q2yNTxDFwtd1sA0Q4jbUa2QnjXI-lLbR8AL6a0Mpwpg8zB6CkEALJx1BHFiiBjd08C5cz1fGwFFCHF5efSlCNouD-trAQuGSWaHDSbBCAnth2pIdZFAd052mRJ7XE2jb54
Feb 12 03:58:43 volumio volumio[21326]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-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 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-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 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-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 12 03:58:43 volumio volumio[21326]: info: New Spotify access token = BQD9UhZQ6wOBwUe3DREe5Abhi8b53LLCvzpyjx-ayUynFT0kjN23PZSVKeDWzsCq3lldYllyKjKzjy_jCcsgILJOp2-9yFodkEyo0q2yNTxDFwtd1sA0Q4jbUa2QnjXI-lLbR8AL6a0Mpwpg8zB6CkEALJx1BHFiiBjd08C5cz1fGwFFCHF5efSlCNouD-trAQuGSWaHDSbBCAnth2pIdZFAd052mRJ7XE2jb54
Feb 12 03:58:43 volumio volumio[21326]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-06:00" level=info msg="zeroconf server listening on port 33895"
Feb 12 03:58:43 volumio volumio[21326]: info: Starting Shairport Sync
Feb 12 03:58:43 volumio sudo[21612]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Feb 12 03:58:43 volumio volumio[21326]: info: Starting Shairport Sync
Feb 12 03:58:43 volumio sudo[21612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:43 volumio volumio[21326]: info: Starting Shairport Sync
Feb 12 03:58:43 volumio sudo[21612]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:43 volumio sudo[21614]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 03:58:43 volumio sudo[21614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:43 volumio sudo[21617]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 03:58:43 volumio sudo[21617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-06:00" level=debug msg="obtained new client token: AAByYWJT6s4x+GDX7GszQB+NAwWlv1dXEe+/cEXwzsaQpzzDOh+zz7Dn/oHRUmFmMqlTze+a1M6nOsyUp2Lq1zUmf7HOs3sb6ABumjLeSUuPfQca90v+U+U1j2URArg8B/Xgqlgrq2ZMaAlPks0Qq5G1eHPGvbtE7S09lpqgEVde76kZ+sHP7wDL1haxz5qx/qIGZq8SQvb8Q2TIWdTBlSII/mmSg8kym84VCEUGYHU9AZgMRCn5v6RjKw=="
Feb 12 03:58:43 volumio sudo[21619]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 03:58:43 volumio sudo[21619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:43 volumio volumio[21326]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Feb 12 03:58:43 volumio volumio[21326]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 03:58:43 volumio volumio[21326]: info: Output device has changed, restarting MPD
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:43 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 03:58:43 volumio sudo[21625]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Feb 12 03:58:43 volumio sudo[21625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:43 volumio volumio[21326]: info: Output device has changed, restarting Shairport Sync
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:43 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:43 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 03:58:43 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 03:58:43 volumio systemd[1]: shairport-sync.service: Consumed 2.089s CPU time.
Feb 12 03:58:43 volumio sudo[21627]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 03:58:43 volumio sudo[21627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:43 volumio sudo[21625]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:43 volumio sudo[21627]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-06:00" level=debug msg="completed challenge"
Feb 12 03:58:43 volumio volumio[21326]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 03:58:43 volumio sudo[21630]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 03:58:43 volumio sudo[21630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:43 volumio go-librespot[21603]: time="2026-02-12T03:58:43-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 12 03:58:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 03:58:43 volumio sudo[21614]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:43 volumio sudo[21617]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:43 volumio sudo[21619]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:43 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 03:58:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 03:58:43 volumio systemd[1]: mpd.service: Consumed 1.785s CPU time.
Feb 12 03:58:43 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 03:58:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 03:58:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 03:58:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 03:58:43 volumio volumio[21326]: info: MPD Permissions set
Feb 12 03:58:43 volumio volumio[21326]: info: Shairport-Sync Started
Feb 12 03:58:43 volumio volumio[21326]: Error adding Membership: Error: addMembership EINVAL
Feb 12 03:58:43 volumio volumio[21326]: info: Shairport-Sync Started
Feb 12 03:58:43 volumio volumio[21326]: info: Shairport-Sync Started
Feb 12 03:58:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 03:58:43 volumio volumio[21326]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Feb 12 03:58:44 volumio sudo[21660]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Feb 12 03:58:44 volumio sudo[21660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:44 volumio sudo[21660]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:44 volumio volumio[21326]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload  || true
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::volumioGetState
Feb 12 03:58:44 volumio volumio[21326]: info: CorePlayQueue::getTrack 0
Feb 12 03:58:44 volumio volumio[21326]: info: Starting Shairport Sync
Feb 12 03:58:44 volumio sudo[21668]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Feb 12 03:58:44 volumio sudo[21668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:44 volumio sudo[21657]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 03:58:44 volumio sudo[21657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 03:58:44 volumio sudo[21657]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:44 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 03:58:44 volumio sudo[21671]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 03:58:44 volumio sudo[21671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:44 volumio volumio[21326]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"}
Feb 12 03:58:44 volumio volumio[21326]: info: Spotify Successfully logged in
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:58:44 volumio volumio[21326]: info: [1770890324299] CoreMusicLibrary::Adding element Spotify
Feb 12 03:58:44 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:58:44 volumio volumio[21326]: Cannot find translation for source Bandcamp Discover
Feb 12 03:58:44 volumio volumio[21326]: Cannot find translation for source SoundCloud
Feb 12 03:58:44 volumio volumio[21326]: Cannot find translation for source YouTube2
Feb 12 03:58:44 volumio volumio[21326]: Cannot find translation for source YouTube Music
Feb 12 03:58:44 volumio volumio[21326]: Cannot find translation for source Podcast
Feb 12 03:58:44 volumio volumio[21326]: Cannot find translation for source Volusonic
Feb 12 03:58:44 volumio volumio[21326]: Cannot find translation for source Spotify
Feb 12 03:58:44 volumio systemd[1]: Reloading.
Feb 12 03:58:45 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:45 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:45 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:58:45 volumio volumio[21326]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 03:58:46 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 03:58:46 volumio volumio[21326]: info: go-librespot daemon successfully initialized
Feb 12 03:58:47 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 03:58:47 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 03:58:47 volumio sudo[21668]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:47 volumio volumio[21326]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:58:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 85.
Feb 12 03:58:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:47 volumio sudo[21709]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:58:47 volumio sudo[21709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:47 volumio go-librespot[21710]: go-librespot daemon starting...
Feb 12 03:58:47 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 03:58:47 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 03:58:47 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 03:58:47 volumio systemd[1]: shairport-sync.service: Consumed 1.485s CPU time.
Feb 12 03:58:47 volumio go-librespot[21712]: time="2026-02-12T03:58:47-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:47 volumio go-librespot[21712]: time="2026-02-12T03:58:47-06:00" level=debug msg="app state loaded"
Feb 12 03:58:47 volumio go-librespot[21712]: time="2026-02-12T03:58:47-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:47 volumio go-librespot[21712]: time="2026-02-12T03:58:47-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 03:58:48 volumio sudo[21671]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:48 volumio volumio[21326]: info: Shairport-Sync Started
Feb 12 03:58:48 volumio sudo[21709]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:48 volumio volumio[21326]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Feb 12 03:58:48 volumio sudo[21733]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Feb 12 03:58:48 volumio sudo[21733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:48 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 03:58:48 volumio go-librespot[21712]: time="2026-02-12T03:58:48-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 12 03:58:48 volumio go-librespot[21712]: time="2026-02-12T03:58:48-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 12 03:58:48 volumio go-librespot[21712]: time="2026-02-12T03:58:48-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 12 03:58:48 volumio go-librespot[21712]: time="2026-02-12T03:58:48-06:00" level=info msg="zeroconf server listening on port 34857"
Feb 12 03:58:48 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Feb 12 03:58:48 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 03:58:48 volumio sudo[21733]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:48 volumio go-librespot[21712]: time="2026-02-12T03:58:48-06:00" level=debug msg="obtained new client token: AADxor2vjlgpeeSaMDg9/c/9djDZtIbb6yYzJ8eLSHO51gX8CmM/Q/3Ze23Vy27ibL0DtiPcDWUjvIGz/MPdYGqQxQJAVgWlgYaWjb+RIJCPYUKibIWvwrCzzkpzR1yftUh9VqqrmnGn1l7pBl/rK911xeeoQ08PzzII24aaOMTSmj2t0bfx41dzJcEkynqzyypEf0ojdXEPlbvqx6lsdO1In7sagTe+q5gH1lZt7fFT3RFrQxxM4Zk6hg=="
Feb 12 03:58:48 volumio go-librespot[21712]: time="2026-02-12T03:58:48-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:48 volumio go-librespot[21712]: time="2026-02-12T03:58:48-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:48 volumio go-librespot[21712]: time="2026-02-12T03:58:48-06:00" level=debug msg="completed challenge"
Feb 12 03:58:48 volumio go-librespot[21712]: time="2026-02-12T03:58:48-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 12 03:58:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:48 volumio volumio[21326]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:58:48 volumio sudo[21738]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:58:48 volumio sudo[21738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:49 volumio sudo[21738]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:49 volumio volumio[21326]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Feb 12 03:58:49 volumio sudo[21742]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Feb 12 03:58:49 volumio sudo[21742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:49 volumio sudo[21742]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:49 volumio volumio[21326]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Feb 12 03:58:49 volumio sudo[21745]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Feb 12 03:58:49 volumio sudo[21745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:49 volumio mpd[21673]: 2026-02-12T03:58:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 12 03:58:49 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 03:58:49 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 03:58:49 volumio sudo[21745]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:49 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 12 03:58:49 volumio sudo[21630]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:49 volumio sudo[21544]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:49 volumio sudo[21554]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:49 volumio volumio[21326]: info: Initializing connection to go-librespot Websocket
Feb 12 03:58:49 volumio volumio[21326]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 03:58:49 volumio volumio[21326]:   assert.ok(self.idling)
Feb 12 03:58:49 volumio volumio[21326]: error: The expression evaluated to a falsy value:
Feb 12 03:58:49 volumio volumio[21326]:   assert.ok(self.idling)
Feb 12 03:58:49 volumio volumio[21326]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 03:58:49 volumio volumio[21326]:   assert.ok(self.idling)
Feb 12 03:58:49 volumio volumio[21326]: error: The expression evaluated to a falsy value:
Feb 12 03:58:49 volumio volumio[21326]:   assert.ok(self.idling)
Feb 12 03:58:49 volumio volumio[21326]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:58:49 volumio volumio[21326]: info: MPD running with PID21673
Feb 12 03:58:49 volumio volumio[21326]:  ,establishing connection
Feb 12 03:58:49 volumio volumio[21326]: error: updateQueue error: null
Feb 12 03:58:49 volumio volumio[21326]: error: updateQueue error: null
Feb 12 03:58:49 volumio volumio[21326]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:58:49 volumio sudo[21756]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:58:49 volumio sudo[21756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:49 volumio sudo[21756]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:50 volumio volumio[21326]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:58:50 volumio sudo[21759]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:58:50 volumio sudo[21759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:50 volumio sudo[21759]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:50 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 03:58:50 volumio volumio[21326]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:58:51 volumio sudo[21763]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:58:51 volumio sudo[21763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:51 volumio sudo[21763]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:51 volumio volumio[21326]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:58:51 volumio sudo[21766]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:58:51 volumio sudo[21766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 86.
Feb 12 03:58:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:51 volumio go-librespot[21768]: go-librespot daemon starting...
Feb 12 03:58:51 volumio sudo[21766]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:51 volumio go-librespot[21769]: time="2026-02-12T03:58:51-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:51 volumio go-librespot[21769]: time="2026-02-12T03:58:51-06:00" level=debug msg="app state loaded"
Feb 12 03:58:51 volumio go-librespot[21769]: time="2026-02-12T03:58:51-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:51 volumio go-librespot[21769]: time="2026-02-12T03:58:51-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:51 volumio go-librespot[21769]: time="2026-02-12T03:58:51-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 12 03:58:51 volumio go-librespot[21769]: time="2026-02-12T03:58:51-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 12 03:58:51 volumio go-librespot[21769]: time="2026-02-12T03:58:51-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 12 03:58:51 volumio go-librespot[21769]: time="2026-02-12T03:58:51-06:00" level=info msg="zeroconf server listening on port 40575"
Feb 12 03:58:52 volumio go-librespot[21769]: time="2026-02-12T03:58:52-06:00" level=debug msg="obtained new client token: AADxB+XmKxO2SCkwvQE+1ZrMuOQ08PksQFefeHlIkTCuNdybJ7LQ3Alh1+dfBy/ibcHKJE40gHqxXQ2Fj0VUdjBm0jzMHA/2FjGlVoGvLTf5bYWXC/quyClTjMvTxiarts2EaCY2vh5NIL4+DuWVTr7cYypdtB/p3WU3FzgSAJ6Wi1AYtmQVYW3iiWRaFjbn6tugTV6sjO/V18r2t74sNrdMheDyg7hZIEEb6f/RkdUfb4G78cJnuns3GA=="
Feb 12 03:58:52 volumio go-librespot[21769]: time="2026-02-12T03:58:52-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:52 volumio go-librespot[21769]: time="2026-02-12T03:58:52-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:52 volumio go-librespot[21769]: time="2026-02-12T03:58:52-06:00" level=debug msg="completed challenge"
Feb 12 03:58:52 volumio go-librespot[21769]: time="2026-02-12T03:58:52-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 12 03:58:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:52 volumio volumio[21326]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:58:52 volumio sudo[21777]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:58:52 volumio sudo[21777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:52 volumio sudo[21777]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:52 volumio volumio[21326]: info: Completed starting Core Plugins
Feb 12 03:58:52 volumio volumio[21326]: info: -------------------------------------------
Feb 12 03:58:52 volumio volumio[21326]: info: -----    MyVolumio plugins startup     ----
Feb 12 03:58:52 volumio volumio[21326]: info: -------------------------------------------
Feb 12 03:58:52 volumio volumio[21326]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 12 03:58:52 volumio sudo[21780]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 03:58:52 volumio sudo[21780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:52 volumio sudo[21782]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 03:58:52 volumio sudo[21782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:52 volumio sudo[21785]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 03:58:52 volumio sudo[21785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:58:52 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Feb 12 03:58:52 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Feb 12 03:58:52 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Feb 12 03:58:52 volumio volumio[21326]: info: Initializing connection to go-librespot Websocket
Feb 12 03:58:52 volumio volumio[21326]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:58:52 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Feb 12 03:58:52 volumio sudo[21782]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:52 volumio sudo[21785]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:52 volumio sudo[21780]: pam_unix(sudo:session): session closed for user root
Feb 12 03:58:52 volumio volumio[21326]: info: Successfully started MPD Monitor
Feb 12 03:58:52 volumio mpd_monitor.sh[21788]: MPD Monitor Service: Starting MPD Monitor Service
Feb 12 03:58:52 volumio volumio[21326]: info: Successfully started MPD Monitor
Feb 12 03:58:52 volumio volumio[21326]: info: Successfully started MPD Monitor
Feb 12 03:58:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87.
Feb 12 03:58:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:55 volumio go-librespot[21792]: go-librespot daemon starting...
Feb 12 03:58:55 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Feb 12 03:58:55 volumio go-librespot[21794]: time="2026-02-12T03:58:55-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:55 volumio go-librespot[21794]: time="2026-02-12T03:58:55-06:00" level=debug msg="app state loaded"
Feb 12 03:58:55 volumio go-librespot[21794]: time="2026-02-12T03:58:55-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:55 volumio go-librespot[21794]: time="2026-02-12T03:58:55-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:55 volumio volumio[21326]: info: Initializing connection to go-librespot Websocket
Feb 12 03:58:56 volumio go-librespot[21794]: time="2026-02-12T03:58:56-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 12 03:58:56 volumio go-librespot[21794]: time="2026-02-12T03:58:56-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 12 03:58:56 volumio go-librespot[21794]: time="2026-02-12T03:58:56-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 12 03:58:56 volumio go-librespot[21794]: time="2026-02-12T03:58:56-06:00" level=info msg="zeroconf server listening on port 39463"
Feb 12 03:58:56 volumio go-librespot[21794]: time="2026-02-12T03:58:56-06:00" level=debug msg="obtained new client token: AACgPC8A1IXenZ9w/fH8OebIfP5CYxesdedo0RIUxuKbT0IldFTbXt1ktEdupuQ2tGyNns4KZzsUIAaXXlOgIEpHxe+QEVT23rhQpDMVzJzI4blmjuC7LqHjWvagSulIAIOB+Jj6Z7mW6grgOa121Sl/JAoTAbHIRAHpNE5rN2Kmo/uGJ+pwz9jddDF0FZt4fq77+n8+doxLLS6WPiF1KEzCy1X3SYqDTXk//lj9g5B5q+IA6FYP7Wk="
Feb 12 03:58:56 volumio go-librespot[21794]: time="2026-02-12T03:58:56-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:58:56 volumio go-librespot[21794]: time="2026-02-12T03:58:56-06:00" level=debug msg="new websocket client"
Feb 12 03:58:56 volumio go-librespot[21794]: time="2026-02-12T03:58:56-06:00" level=debug msg="completed keyexchange"
Feb 12 03:58:56 volumio go-librespot[21794]: time="2026-02-12T03:58:56-06:00" level=debug msg="completed challenge"
Feb 12 03:58:56 volumio go-librespot[21794]: time="2026-02-12T03:58:56-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 12 03:58:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:58:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:58:56 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 03:58:56 volumio volumio[21326]: info: Connection to go-librespot Websocket established
Feb 12 03:58:57 volumio volumio[21326]: info: Connection to go-librespot Websocket closed
Feb 12 03:58:57 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully.
Feb 12 03:58:57 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Feb 12 03:58:57 volumio systemd[1]: setdatetime-helper.service: Consumed 1.997s CPU time.
Feb 12 03:58:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 88.
Feb 12 03:58:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:58:59 volumio go-librespot[21840]: go-librespot daemon starting...
Feb 12 03:58:59 volumio go-librespot[21841]: time="2026-02-12T03:58:59-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:58:59 volumio go-librespot[21841]: time="2026-02-12T03:58:59-06:00" level=debug msg="app state loaded"
Feb 12 03:58:59 volumio go-librespot[21841]: time="2026-02-12T03:58:59-06:00" level=debug msg="stored credentials not found"
Feb 12 03:58:59 volumio go-librespot[21841]: time="2026-02-12T03:58:59-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:58:59 volumio go-librespot[21841]: time="2026-02-12T03:58:59-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 12 03:58:59 volumio go-librespot[21841]: time="2026-02-12T03:58:59-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 12 03:58:59 volumio go-librespot[21841]: time="2026-02-12T03:58:59-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 12 03:58:59 volumio go-librespot[21841]: time="2026-02-12T03:58:59-06:00" level=info msg="zeroconf server listening on port 35841"
Feb 12 03:58:59 volumio volumio[21326]: info: Getting Spotify volume
Feb 12 03:58:59 volumio go-librespot[21841]: time="2026-02-12T03:58:59-06:00" level=debug msg="obtained new client token: AAAFKWrlHWbgR+ch6ipiwvOf1GGQBKS/OgCrEMivH8dkTgl2/AeyX6/oOx2wS+RSN5eQ6YClotRGbiXwhjIhn8ISxiY4CFUx7/EBZY+eMEtNJ4vvKIIx1ErOkoITQYmWOXeTel0+I3JMd462msrNSpQhSJZvqoHKYuUoI1P1SSxvbl+PLitKNnL+RjVxLI5Bm9vVia+qbzs7bibCVR8eM8BFlIwa1GGLndR0AWF5Qs8Aek+ubHpmNy80rg=="
Feb 12 03:58:59 volumio volumio[21326]: 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 12 03:58:59 volumio go-librespot[21841]: time="2026-02-12T03:58:59-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:59:00 volumio volumio[21326]: info: CoreCommandRouter::volumioGetState
Feb 12 03:59:00 volumio volumio[21326]: info: CorePlayQueue::getTrack 0
Feb 12 03:59:00 volumio volumio[21326]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 12 03:59:00 volumio volumio[21326]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 12 03:59:00 volumio volumio[21326]: SPOTIFY: VOLUMIO VOLUME 100
Feb 12 03:59:00 volumio volumio[21326]: info: Aligning Spotify Volume to Volumio Volume
Feb 12 03:59:00 volumio volumio[21326]: info: CoreCommandRouter::volumioGetState
Feb 12 03:59:00 volumio volumio[21326]: info: CorePlayQueue::getTrack 0
Feb 12 03:59:00 volumio volumio[21326]: info: Setting Spotify Volume from Volumio: 100
Feb 12 03:59:00 volumio go-librespot[21841]: time="2026-02-12T03:59:00-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:00 volumio go-librespot[21841]: time="2026-02-12T03:59:00-06:00" level=debug msg="completed challenge"
Feb 12 03:59:00 volumio go-librespot[21841]: time="2026-02-12T03:59:00-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 12 03:59:00 volumio volumio[21326]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 03:59:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:00 volumio volumio[21326]: Error: socket hang up
Feb 12 03:59:00 volumio volumio[21326]:     at connResetException (node:internal/errors:720:14)
Feb 12 03:59:00 volumio volumio[21326]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 12 03:59:00 volumio volumio[21326]:     at Socket.emit (node:events:526:35)
Feb 12 03:59:00 volumio volumio[21326]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 12 03:59:00 volumio volumio[21326]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 12 03:59:00 volumio volumio[21326]:   code: 'ECONNRESET',
Feb 12 03:59:00 volumio volumio[21326]:   response: undefined
Feb 12 03:59:00 volumio volumio[21326]: }
Feb 12 03:59:00 volumio volumio[21326]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 03:59:00 volumio sudo[21862]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 03:58'
Feb 12 03:59:00 volumio sudo[21862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:00 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 03:59:00 volumio sudo[21862]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:01 volumio volumio-remote-updater[2265]: [2026-02-12 03:59:01] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 12 03:59:01 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:01 volumio volumio-remote-updater[2265]: [2026-02-12 03:59:01] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 12 03:59:01 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 12 03:59:01 volumio systemd[1]: volumio.service: Consumed 47.782s CPU time.
Feb 12 03:59:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 03:59:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 03:59:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6155.
Feb 12 03:59:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 12 03:59:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 12 03:59:02 volumio systemd[1]: volumio.service: Consumed 47.782s CPU time.
Feb 12 03:59:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 12 03:59:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 12 03:59:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 89.
Feb 12 03:59:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:03 volumio go-librespot[21893]: go-librespot daemon starting...
Feb 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-06:00" level=debug msg="app state loaded"
Feb 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-06:00" level=debug msg="stored credentials not found"
Feb 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-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 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-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 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-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 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-06:00" level=info msg="zeroconf server listening on port 35933"
Feb 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-06:00" level=debug msg="obtained new client token: AAD+AQTcK5Fkq4XQnv63plGWNwAVr6dXYx/c9KQoJ/f6PKYZyBPCBPz+Grn+RV6r2jHBT2/uS1CnFZ6JchLq5m+lO62QqoTC5sNhk9DTC4AChkaYzAyUSzRivVvcWPJSb7KbvzkDPXu4yaXVA4rsTQ3TIy9ecmaZGvOQY6SL2x+znHuT6rhQRfDzhDIWNrp7MYYh2E0ardeRkOVBMF3HL2GLHLA6SeNmmKTEQMtif6dxMBelcHyupO9WGA=="
Feb 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-06:00" level=debug msg="completed challenge"
Feb 12 03:59:03 volumio go-librespot[21894]: time="2026-02-12T03:59:03-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 12 03:59:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:04 volumio volumio[21878]: info: -------------------------------------------
Feb 12 03:59:04 volumio volumio[21878]: info: -----            Volumio3              ----
Feb 12 03:59:04 volumio volumio[21878]: info: -------------------------------------------
Feb 12 03:59:04 volumio volumio[21878]: info: -----          System startup          ----
Feb 12 03:59:04 volumio volumio[21878]: info: -------------------------------------------
Feb 12 03:59:05 volumio volumio[21878]: info: MYVOLUMIO Environment detected
Feb 12 03:59:05 volumio volumio[21878]: info: Plugin folders cleanup
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning into folder /volumio/app/plugins/
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category audio_interface
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category miscellanea
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category music_service
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category plugins.json
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category system_controller
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category user_interface
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning into folder /data/plugins/
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category audio_interface
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category music_service
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category system_controller
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category system_hardware
Feb 12 03:59:05 volumio volumio[21878]: info: Scanning category user_interface
Feb 12 03:59:05 volumio volumio[21878]: info: Plugin folders cleanup completed
Feb 12 03:59:05 volumio volumio[21878]: info: -------------------------------------------
Feb 12 03:59:05 volumio volumio[21878]: info: -----      Core plugins startup        ----
Feb 12 03:59:05 volumio volumio[21878]: info: -------------------------------------------
Feb 12 03:59:05 volumio volumio[21878]: info: Loading plugins from folder /volumio/app/plugins/
Feb 12 03:59:05 volumio volumio[21878]: info: Adding plugin upnp to MyMusic Plugins
Feb 12 03:59:05 volumio volumio[21878]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 12 03:59:05 volumio volumio[21878]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 12 03:59:05 volumio volumio[21878]: info: Loading plugins from folder /data/plugins/
Feb 12 03:59:05 volumio volumio[21878]: info: Loading plugin "system"...
Feb 12 03:59:05 volumio volumio[21878]: info: Loading plugin "appearance"...
Feb 12 03:59:06 volumio volumio[21878]: info: Loading plugin "network"...
Feb 12 03:59:06 volumio volumio[21878]: info: Refreshing Cached IP Addresses
Feb 12 03:59:06 volumio sudo[21915]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 03:59:06 volumio sudo[21915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:06 volumio sudo[21917]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 03:59:06 volumio volumio[21878]: info: Loading plugin "services"...
Feb 12 03:59:06 volumio sudo[21917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:06 volumio volumio[21878]: info: Loading plugin "alsa_controller"...
Feb 12 03:59:06 volumio sudo[21915]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:06 volumio sudo[21917]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:06 volumio sudo[21924]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 12 03:59:06 volumio sudo[21924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:06 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 03:59:06 volumio volumio[21878]: info: Loading plugin "wizard"...
Feb 12 03:59:06 volumio volumio[21878]: info: Loading plugin "networkfs"...
Feb 12 03:59:06 volumio volumio[21878]: info: Starting Udev Watcher for removable devices
Feb 12 03:59:06 volumio volumio[21878]: info: Ignoring mount for partition: boot
Feb 12 03:59:06 volumio volumio[21878]: info: Ignoring mount for partition: volumio
Feb 12 03:59:06 volumio volumio[21878]: info: Ignoring mount for partition: volumio_data
Feb 12 03:59:06 volumio volumio[21878]: info: Mounting Device Wikipedia
Feb 12 03:59:06 volumio sudo[21954]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Feb 12 03:59:06 volumio sudo[21954]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:06 volumio sudo[21954]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:06 volumio volumio[21878]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 03:59:06 volumio volumio[21878]:        dmesg(1) may have more information after failed mount system call.
Feb 12 03:59:06 volumio volumio[21878]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Feb 12 03:59:06 volumio volumio[21878]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Feb 12 03:59:06 volumio volumio[21878]:        dmesg(1) may have more information after failed mount system call.
Feb 12 03:59:06 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 03:59:06 volumio volumio[21878]: info: Loading plugin "volumio_command_line_client"...
Feb 12 03:59:06 volumio volumio[21878]: info: Loading plugin "upnp"...
Feb 12 03:59:06 volumio volumio[21878]: info: [1770890346818] Starting Upmpd Daemon
Feb 12 03:59:06 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 03:59:06 volumio volumio[21878]: info: Loading plugin "my_music"...
Feb 12 03:59:06 volumio volumio[21878]: info: Loading plugin "mpd"...
Feb 12 03:59:06 volumio volumio-remote-updater[2265]: [2026-02-12 03:59:06] [connect] Successful connection
Feb 12 03:59:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 90.
Feb 12 03:59:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:07 volumio sudo[21924]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:07 volumio go-librespot[21957]: go-librespot daemon starting...
Feb 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-06:00" level=debug msg="app state loaded"
Feb 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-06:00" level=debug msg="stored credentials not found"
Feb 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:59:07 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 03:59:07 volumio volumio[21878]: info: Loading plugin "upnp_browser"...
Feb 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-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 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-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 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-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 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-06:00" level=info msg="zeroconf server listening on port 42557"
Feb 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-06:00" level=debug msg="obtained new client token: AABusA8dBxa8d/4wwWMdRUQZb3pBzLQj8ZxTF6INxcwPSyoeqb3EzawrLirdCjzipb2AEpzlOUl4HIuEdkE3xSD0sLtJKMHqPy0dXIkEVRW0qrXtrOAv6BYyzcIfHXJWPtRt1nw1ZP3+bD72H6RjYuJQ186CFAcyxGzkpeuARgpazQn8eEKWIGTqIa0GGVCawp4bTh+i+ZuRAlwjkKUwtbQ6HNzTPzWE6Joqpc3W1w/LnyH0w9l+R6sdAQ=="
Feb 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-06:00" level=debug msg="completed challenge"
Feb 12 03:59:07 volumio go-librespot[21958]: time="2026-02-12T03:59:07-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 12 03:59:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:10 volumio volumio[21878]: info: Loading plugin "alarm-clock"...
Feb 12 03:59:10 volumio volumio[21878]: info: Loading plugin "airplay_emulation"...
Feb 12 03:59:10 volumio volumio[21878]: info: Starting Shairport Sync
Feb 12 03:59:10 volumio volumio[21878]: info: Loading plugin "last_100"...
Feb 12 03:59:10 volumio volumio[21878]: info: Loading plugin "webradio"...
Feb 12 03:59:10 volumio volumio[21878]: info: Loading plugin "i2s_dacs"...
Feb 12 03:59:10 volumio volumio[21878]: info: I2S DAC not set, start Auto-detection
Feb 12 03:59:10 volumio volumio[21878]: info: Loading plugin "volumiodiscovery"...
Feb 12 03:59:10 volumio volumio[21878]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 03:59:10 volumio volumio[21878]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 03:59:10 volumio volumio[21878]: *** WARNING *** For more information see 
Feb 12 03:59:10 volumio volumio[21878]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 03:59:10 volumio volumio[21878]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 03:59:10 volumio volumio[21878]: *** WARNING *** For more information see 
Feb 12 03:59:10 volumio node[21878]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 12 03:59:10 volumio node[21878]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 03:59:10 volumio node[21878]: *** WARNING *** For more information see 
Feb 12 03:59:10 volumio node[21878]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 12 03:59:10 volumio node[21878]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 12 03:59:10 volumio node[21878]: *** WARNING *** For more information see 
Feb 12 03:59:10 volumio volumio[21878]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 12 03:59:10 volumio volumio[21878]: info: Discovery: Started advertising with name: Volumio
Feb 12 03:59:10 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 12 03:59:10 volumio volumio[21878]: info: Loading plugin "bandcamp"...
Feb 12 03:59:10 volumio nmbd[1061]: [2026/02/12 03:59:10.685457,  0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response)
Feb 12 03:59:10 volumio nmbd[1061]:   query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.221 for name WORKGROUP<1d>.
Feb 12 03:59:10 volumio nmbd[1061]:   This response was from IP 192.168.1.112, reporting an IP address of 192.168.1.112.
Feb 12 03:59:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 91.
Feb 12 03:59:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:11 volumio go-librespot[21969]: go-librespot daemon starting...
Feb 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-06:00" level=debug msg="app state loaded"
Feb 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-06:00" level=debug msg="stored credentials not found"
Feb 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-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 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-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 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-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 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-06:00" level=info msg="zeroconf server listening on port 34481"
Feb 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-06:00" level=debug msg="obtained new client token: AAC6OfzOFy8ke1rdVdcAH7RVfz7EVkfUIIe1CgH+Wl0N5f6KsBB/HhFsmQG5AujhhvUm+6q722HsPSP+eOe9OkElqmi4rnODMmof4bib4/8POrVzbYaSJMlDteBdNLaU720IpIqjvA+fmc0R8UCD+9ClMurSp8DipRNrQDRt8eIMtCdYi2Jzt+ZaGCKWZXQGc5FiVuf4mXqign+svzs3F9t1yBr6qKZVGZtyVbHROACTJMtyTG6nibtNtQ=="
Feb 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-06:00" level=debug msg="completed challenge"
Feb 12 03:59:11 volumio go-librespot[21970]: time="2026-02-12T03:59:11-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 12 03:59:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:11 volumio volumio[21878]: info: Plugin calmradio is not enabled
Feb 12 03:59:11 volumio volumio[21878]: info: Loading plugin "soundcloud"...
Feb 12 03:59:12 volumio volumio[21878]: info: Loading plugin "spop"...
Feb 12 03:59:13 volumio volumio[21878]: info: Loading plugin "squeezelite_mc"...
Feb 12 03:59:13 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 03:59:13 volumio volumio[21878]: info: Loading plugin "youtube2"...
Feb 12 03:59:14 volumio volumio[21878]: info: Loading plugin "ytcr"...
Feb 12 03:59:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 92.
Feb 12 03:59:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:14 volumio go-librespot[21982]: go-librespot daemon starting...
Feb 12 03:59:14 volumio go-librespot[21983]: time="2026-02-12T03:59:14-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:14 volumio go-librespot[21983]: time="2026-02-12T03:59:14-06:00" level=debug msg="app state loaded"
Feb 12 03:59:14 volumio go-librespot[21983]: time="2026-02-12T03:59:14-06:00" level=debug msg="stored credentials not found"
Feb 12 03:59:14 volumio go-librespot[21983]: time="2026-02-12T03:59:14-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:59:15 volumio go-librespot[21983]: time="2026-02-12T03:59:15-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 12 03:59:15 volumio go-librespot[21983]: time="2026-02-12T03:59:15-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 12 03:59:15 volumio go-librespot[21983]: time="2026-02-12T03:59:15-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 12 03:59:15 volumio go-librespot[21983]: time="2026-02-12T03:59:15-06:00" level=info msg="zeroconf server listening on port 33667"
Feb 12 03:59:15 volumio go-librespot[21983]: time="2026-02-12T03:59:15-06:00" level=debug msg="obtained new client token: AACVUFGviuMcPhCbv+FABmHuFCHbellHwD7Cp6vCmCZHhsBAgLcZXEaLR/2k6/QZa7dSXlaqnYw4BgM7D6K5HVg0yNp8Dpi3tjffmrYa/yrJtqFROSck2aoIFo5zvibzjtEsHCkkkMt5QrwGEOl9Q9wfEPTjGH9rn6VHiuAmH4R+HKqBPTELm0NbTfbXZdXUUrCNXJv6XPwWVHBNCgDWWPRi3iDWnDjjeH8OYbuU+DMm02c0mAMLIjUzUQ=="
Feb 12 03:59:15 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 03:59:15 volumio go-librespot[21983]: time="2026-02-12T03:59:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:59:15 volumio go-librespot[21983]: time="2026-02-12T03:59:15-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:15 volumio go-librespot[21983]: time="2026-02-12T03:59:15-06:00" level=debug msg="completed challenge"
Feb 12 03:59:15 volumio go-librespot[21983]: time="2026-02-12T03:59:15-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 12 03:59:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:16 volumio volumio[21878]: info: Loading plugin "ytmusic"...
Feb 12 03:59:17 volumio volumio[21878]: info: Plugin now_playing is not enabled
Feb 12 03:59:17 volumio volumio[21878]: info: Loading plugin "outputs"...
Feb 12 03:59:17 volumio volumio[21878]: info: Loading plugin "albumart"...
Feb 12 03:59:17 volumio volumio[21878]: info: Plugin example_plugin is not enabled
Feb 12 03:59:17 volumio volumio[21878]: info: Loading plugin "inputs"...
Feb 12 03:59:17 volumio volumio[21878]: info: Loading plugin "updater_comm"...
Feb 12 03:59:17 volumio volumio[21878]: info: Plugin mpdemulation is not enabled
Feb 12 03:59:17 volumio volumio[21878]: info: Loading plugin "rest_api"...
Feb 12 03:59:17 volumio volumio[21878]: info: Loading plugin "websocket"...
Feb 12 03:59:17 volumio volumio[21878]: info: Starting Socket.io Server version 1.7.4
Feb 12 03:59:17 volumio volumio[21878]: info: Plugin fusiondsp is not enabled
Feb 12 03:59:17 volumio volumio[21878]: info: Plugin mpdoutput is not enabled
Feb 12 03:59:17 volumio volumio[21878]: info: Plugin RoonBridge is not enabled
Feb 12 03:59:17 volumio volumio[21878]: info: Loading plugin "podcast"...
Feb 12 03:59:18 volumio volumio[21878]: info: ControllerPodcast::constructor
Feb 12 03:59:18 volumio volumio[21878]: info: Loading plugin "volusonic"...
Feb 12 03:59:18 volumio volumio[22005]: Forking 3 albumart workers
Feb 12 03:59:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93.
Feb 12 03:59:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:18 volumio go-librespot[22045]: go-librespot daemon starting...
Feb 12 03:59:18 volumio go-librespot[22046]: time="2026-02-12T03:59:18-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:18 volumio go-librespot[22046]: time="2026-02-12T03:59:18-06:00" level=debug msg="app state loaded"
Feb 12 03:59:18 volumio go-librespot[22046]: time="2026-02-12T03:59:18-06:00" level=debug msg="stored credentials not found"
Feb 12 03:59:18 volumio go-librespot[22046]: time="2026-02-12T03:59:18-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:59:19 volumio go-librespot[22046]: time="2026-02-12T03:59: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 12 03:59:19 volumio go-librespot[22046]: time="2026-02-12T03:59: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 12 03:59:19 volumio go-librespot[22046]: time="2026-02-12T03:59: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 12 03:59:19 volumio go-librespot[22046]: time="2026-02-12T03:59:19-06:00" level=info msg="zeroconf server listening on port 43629"
Feb 12 03:59:19 volumio go-librespot[22046]: time="2026-02-12T03:59:19-06:00" level=debug msg="obtained new client token: AAC0YEeS7GDGEG+DALvgP8isGedTzsc9sudyzvsYZyekHlAUARrQX52Hma8q6A1H+Wq8vwNavNotAm7ebK+aXHHzdtOHSd27FNPmzVifpTerQPIQywewEta9pOoQqDcAuI9mTxEkaulzViTM4nSVrdGgtPWfVVf4YqpjHUmAq93lCCUh3n2ONsgfLh1OPbmnpmHXgm7k2VqOwfDZYeK2AO870dfzeOMh5KNxPoEP//bL1CD1q+i8AN/WaA=="
Feb 12 03:59:19 volumio go-librespot[22046]: time="2026-02-12T03:59:19-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Feb 12 03:59:19 volumio volumio-remote-updater[2265]: [2026-02-12 03:59:19] [connect] Successful connection
Feb 12 03:59:19 volumio go-librespot[22046]: time="2026-02-12T03:59:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:443"
Feb 12 03:59:19 volumio go-librespot[22046]: time="2026-02-12T03:59:19-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:19 volumio go-librespot[22046]: time="2026-02-12T03:59:19-06:00" level=debug msg="completed challenge"
Feb 12 03:59:19 volumio go-librespot[22046]: time="2026-02-12T03:59:19-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 12 03:59:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:19 volumio volumio[21878]: info: Applying required configuration parameters for plugin volusonic
Feb 12 03:59:19 volumio volumio[21878]: info: Loading plugin "backup_restore"...
Feb 12 03:59:20 volumio volumio[22015]: Starting albumart workers
Feb 12 03:59:20 volumio volumio[22016]: Starting albumart workers
Feb 12 03:59:20 volumio volumio[22017]: Starting albumart workers
Feb 12 03:59:20 volumio volumio[21878]: info: Applying required configuration parameters for plugin backup_restore
Feb 12 03:59:20 volumio volumio[21878]: info: Plugin rpi_eeprom_config is not enabled
Feb 12 03:59:20 volumio volumio[21878]: info: Plugin rpi_eeprom_updater is not enabled
Feb 12 03:59:20 volumio volumio[21878]: info: Loading plugin "scheduledrestart"...
Feb 12 03:59:20 volumio volumio[21878]: info: Applying required configuration parameters for plugin scheduledrestart
Feb 12 03:59:20 volumio volumio[21878]: info: Plugin Bluetoothremote is not enabled
Feb 12 03:59:20 volumio volumio[21878]: info: Plugin music_services_shield is not enabled
Feb 12 03:59:20 volumio volumio[21878]: info: Loading plugin "Systeminfo"...
Feb 12 03:59:20 volumio volumio[21878]: info: Plugin peppymeterbasic is not enabled
Feb 12 03:59:20 volumio volumio[21878]: info: Loading plugin "peppyspectrum"...
Feb 12 03:59:21 volumio volumio[21878]: info: Loading i18n strings for locale en
Feb 12 03:59:21 volumio volumio[21878]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 03:59:21 volumio volumio[21878]: Updating browse sources language
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::initPlayerControls
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 03:59:21 volumio volumio[21878]: Express server listening on port 3000
Feb 12 03:59:21 volumio volumio[21878]:  [Metrics]  WebUI:  17s 649.57ms 
Feb 12 03:59:21 volumio volumio[21878]: info: CoreStateMachine::resetVolumioState
Feb 12 03:59:21 volumio volumio[21878]: info: CoreStateMachine::getcurrentVolume
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:59:21 volumio sudo[22076]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 12 03:59:21 volumio sudo[22076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:21 volumio sudo[22076]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:21 volumio sudo[22078]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 12 03:59:21 volumio sudo[22078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:21 volumio sudo[22078]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:21 volumio volumio[21878]: info: Volumio Network Manager: Network status updated: 1
Feb 12 03:59:21 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 03:59:21 volumio volumio[21878]: info: VolumeController:: Volume=100 Mute =false
Feb 12 03:59:21 volumio volumio[21878]: info: CoreStateMachine::pushState
Feb 12 03:59:21 volumio volumio[21878]: info: CorePlayQueue::getTrack 0
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::volumioPushState
Feb 12 03:59:21 volumio volumio[21878]: info: CoreStateMachine::updateTrackBlock
Feb 12 03:59:21 volumio volumio[21878]: info: CorePlayQueue::getTrackBlock
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 03:59:21 volumio volumio-remote-updater[2265]: [2026-02-12 03:59:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770890359 101
Feb 12 03:59:21 volumio volumio[21878]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1
Feb 12 03:59:21 volumio volumio[21878]: info: Reloading queue from file
Feb 12 03:59:21 volumio volumio[21878]: info: CoreStateMachine::setRepeat null single undefined
Feb 12 03:59:21 volumio volumio[21878]: info: CoreStateMachine::pushState
Feb 12 03:59:21 volumio volumio[21878]: info: CorePlayQueue::getTrack 0
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::volumioPushState
Feb 12 03:59:21 volumio volumio[21878]: info: CoreStateMachine::setRandom null
Feb 12 03:59:21 volumio volumio[21878]: info: CoreStateMachine::pushState
Feb 12 03:59:21 volumio volumio[21878]: info: CorePlayQueue::getTrack 0
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::volumioPushState
Feb 12 03:59:21 volumio volumio[21878]: info: Setting Device type: Raspberry PI
Feb 12 03:59:21 volumio volumio[21878]: info: VolumeController:: Volume=100 Mute =false
Feb 12 03:59:21 volumio volumio[21878]: info: CoreStateMachine::pushState
Feb 12 03:59:21 volumio volumio[21878]: info: CorePlayQueue::getTrack 0
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::volumioPushState
Feb 12 03:59:21 volumio volumio[21878]: info: Completed loading Core Plugins
Feb 12 03:59:21 volumio volumio[21878]: info: Preparing to generate the ALSA configuration file
Feb 12 03:59:21 volumio sudo[22092]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 12 03:59:21 volumio sudo[22092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:21 volumio volumio[21878]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 03:59:21 volumio volumio[21878]: info: Discovery: Found device Volumio
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::volumioGetState
Feb 12 03:59:21 volumio volumio[21878]: info: CorePlayQueue::getTrack 0
Feb 12 03:59:21 volumio volumio[21878]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 03:59:21 volumio volumio[21878]: info: Reading ALSA contributions from plugins.
Feb 12 03:59:21 volumio volumio[21878]: info: Discovery: this is already registered,  a135e40e-a404-457b-98f5-36bf71c75954
Feb 12 03:59:21 volumio volumio[21878]: info: Discovery: Found device Volumio
Feb 12 03:59:21 volumio volumio[21878]: info: CoreCommandRouter::volumioGetState
Feb 12 03:59:21 volumio sudo[22092]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:21 volumio volumio[21878]: info: CorePlayQueue::getTrack 0
Feb 12 03:59:22 volumio volumio[21878]: info: Upmpdcli Daemon Started
Feb 12 03:59:22 volumio volumio[21878]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 03:59:22 volumio volumio[21878]: info: Output device has changed, restarting MPD
Feb 12 03:59:22 volumio volumio[21878]: info: Output device has changed, restarting Shairport Sync
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:59:22 volumio sudo[22095]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 03:59:22 volumio sudo[22095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:22 volumio sudo[22095]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:22 volumio sudo[22097]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 03:59:22 volumio sudo[22097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:22 volumio volumio[21878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 03:59:22 volumio volumio[21878]: info: ___________ START PLUGINS ___________
Feb 12 03:59:22 volumio volumio[21878]: info: ControllerMpd::onStart: Initializing MPD
Feb 12 03:59:22 volumio volumio[21878]: info: Creating MPD Configuration file
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:59:22 volumio volumio[21878]: info: [1770890362103] CoreMusicLibrary::Adding element Media Servers
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:22 volumio sudo[22105]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 03:59:22 volumio sudo[22105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:22 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 12 03:59:22 volumio sudo[22105]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:22 volumio sudo[22107]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 03:59:22 volumio sudo[22107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:59:22 volumio volumio[21878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:59:22 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 03:59:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 03:59:22 volumio volumio[21878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 03:59:22 volumio systemd[1]: mpd.service: Consumed 5.665s CPU time.
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:59:22 volumio volumio[21878]: info: [1770890362229] CoreMusicLibrary::Adding element Last_100
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:22 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:59:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 03:59:22 volumio volumio[21878]: info: [1770890362235] CoreMusicLibrary::Adding element Webradio
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 03:59:22 volumio volumio[21878]: info: Initializing BBC Radios
Feb 12 03:59:22 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 03:59:22 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:59:22 volumio volumio[21878]: info: [1770890362324] CoreMusicLibrary::Adding element Bandcamp Discover
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Bandcamp Discover
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:59:22 volumio volumio[21878]: info: [1770890362336] CoreMusicLibrary::Adding element SoundCloud
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Bandcamp Discover
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source SoundCloud
Feb 12 03:59:22 volumio volumio[21878]: info: Creating Spotify config file
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:22 volumio sudo[22128]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 03:59:22 volumio sudo[22128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 03:59:22 volumio sudo[22128]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94.
Feb 12 03:59:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:22 volumio go-librespot[22135]: go-librespot daemon starting...
Feb 12 03:59:22 volumio volumio[21878]: info: [squeezelite_mc] Starting proxy server...
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:59:22 volumio volumio[21878]: info: [1770890362706] CoreMusicLibrary::Adding element YouTube2
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Bandcamp Discover
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source SoundCloud
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube2
Feb 12 03:59:22 volumio go-librespot[22136]: time="2026-02-12T03:59:22-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:59:22 volumio volumio[21878]: info: [1770890362727] CoreMusicLibrary::Adding element YouTube Music
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Bandcamp Discover
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source SoundCloud
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube2
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube Music
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:59:22 volumio volumio[21878]: info: [1770890362740] CoreMusicLibrary::Adding element Podcast
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Bandcamp Discover
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source SoundCloud
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube2
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube Music
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Podcast
Feb 12 03:59:22 volumio volumio[21878]: info: Loading i18n strings for locale en
Feb 12 03:59:22 volumio volumio[21878]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Feb 12 03:59:22 volumio volumio[21878]: Updating browse sources language
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Bandcamp Discover
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source SoundCloud
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube2
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube Music
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Podcast
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Bandcamp Discover
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source SoundCloud
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube2
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube Music
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Podcast
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:59:22 volumio volumio[21878]: info: [1770890362790] CoreMusicLibrary::Adding element Volusonic
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Bandcamp Discover
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source SoundCloud
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube2
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source YouTube Music
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Podcast
Feb 12 03:59:22 volumio volumio[21878]: Cannot find translation for source Volusonic
Feb 12 03:59:22 volumio volumio[21878]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Feb 12 03:59:22 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Feb 12 03:59:22 volumio volumio[21878]: info: Volumio Calling Home
Feb 12 03:59:22 volumio volumio[21878]: info: [squeezelite_mc] Proxy server started on port 34813
Feb 12 03:59:22 volumio volumio[21878]: info: Preparing to generate the ALSA configuration file
Feb 12 03:59:23 volumio go-librespot[22136]: time="2026-02-12T03:59:23-06:00" level=info msg="zeroconf server listening on port 46791"
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::volumioRetrievevolume
Feb 12 03:59:23 volumio volumio[21878]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Feb 12 03:59:23 volumio volumio[21878]: info: Reading ALSA contributions from plugins.
Feb 12 03:59:23 volumio volumio[21878]: info: MPD Permissions set
Feb 12 03:59:23 volumio volumio[21878]: info: MPD Permissions set
Feb 12 03:59:23 volumio volumio[21878]: info: Spotify config file written
Feb 12 03:59:23 volumio sudo[22149]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 12 03:59:23 volumio sudo[22149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:23 volumio volumio[21878]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 12 03:59:23 volumio volumio[21878]: info: VolumeController:: Volume=100 Mute =false
Feb 12 03:59:23 volumio volumio[21878]: info: CoreStateMachine::pushState
Feb 12 03:59:23 volumio volumio[21878]: info: CorePlayQueue::getTrack 0
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::volumioPushState
Feb 12 03:59:23 volumio volumio[21878]: info: [squeezelite_mc] Server discovery started
Feb 12 03:59:23 volumio volumio[21878]: info: [squeezelite_mc] Player finder started
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero  2>&1 || true
Feb 12 03:59:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 12 03:59:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 12 03:59:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: No need to fix Spotify hosts
Feb 12 03:59:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:23 volumio go-librespot[22155]: go-librespot daemon starting...
Feb 12 03:59:23 volumio sudo[22149]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:23 volumio go-librespot[22165]: time="2026-02-12T03:59:23-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:23 volumio go-librespot[22165]: time="2026-02-12T03:59:23-06:00" level=debug msg="app state loaded"
Feb 12 03:59:23 volumio go-librespot[22165]: time="2026-02-12T03:59:23-06:00" level=debug msg="stored credentials not found"
Feb 12 03:59:23 volumio go-librespot[22165]: time="2026-02-12T03:59:23-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:59:23 volumio volumio[21878]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Feb 12 03:59:23 volumio volumio[21878]: info: Volumio called home
Feb 12 03:59:23 volumio go-librespot[22165]: time="2026-02-12T03:59: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 12 03:59:23 volumio go-librespot[22165]: time="2026-02-12T03:59: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 12 03:59:23 volumio go-librespot[22165]: time="2026-02-12T03:59: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 12 03:59:23 volumio volumio[21878]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Feb 12 03:59:23 volumio volumio[21878]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Feb 12 03:59:23 volumio volumio[21878]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Feb 12 03:59:23 volumio go-librespot[22165]: time="2026-02-12T03:59:23-06:00" level=info msg="zeroconf server listening on port 41421"
Feb 12 03:59:23 volumio volumio[21878]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 03:59:23 volumio volumio[21878]: SPOTIFY: BQAF317th46zzhVujErmoU09MOj0MOvsTS8qJ1G5z_PZKI7Tnof8hsC29mRb1qbGhsdmLlIBgy30xnFuRUMegxsjA1grhm5lnjlgK92OA4F9exnFPi80uWbdpslDX7g65qfjqxoYML9GDVrUFvMKeg4ZuDJrEuEbOyOoUnUNgAEmIeK9eI19smP-Qd6iOtYqSpPJ1_0Vr7v3lYPNIxytKuYbpqo38HdxnK4I0qY
Feb 12 03:59:23 volumio volumio[21878]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 12 03:59:23 volumio volumio[21878]: info: New Spotify access token = BQAF317th46zzhVujErmoU09MOj0MOvsTS8qJ1G5z_PZKI7Tnof8hsC29mRb1qbGhsdmLlIBgy30xnFuRUMegxsjA1grhm5lnjlgK92OA4F9exnFPi80uWbdpslDX7g65qfjqxoYML9GDVrUFvMKeg4ZuDJrEuEbOyOoUnUNgAEmIeK9eI19smP-Qd6iOtYqSpPJ1_0Vr7v3lYPNIxytKuYbpqo38HdxnK4I0qY
Feb 12 03:59:23 volumio volumio[21878]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 12 03:59:23 volumio volumio[21878]: info: Starting Shairport Sync
Feb 12 03:59:23 volumio volumio[21878]: info: Starting Shairport Sync
Feb 12 03:59:23 volumio volumio[21878]: info: Starting Shairport Sync
Feb 12 03:59:23 volumio sudo[22174]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Feb 12 03:59:23 volumio sudo[22174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:23 volumio sudo[22176]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 03:59:23 volumio sudo[22176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:23 volumio sudo[22174]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:23 volumio sudo[22178]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 03:59:23 volumio sudo[22178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:23 volumio sudo[22182]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 03:59:23 volumio sudo[22182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:23 volumio volumio[21878]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Feb 12 03:59:23 volumio volumio[21878]: info: Asound.conf file unchanged, so no further update is needed
Feb 12 03:59:23 volumio volumio[21878]: info: Output device has changed, restarting MPD
Feb 12 03:59:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 03:59:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 03:59:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 03:59:23 volumio systemd[1]: shairport-sync.service: Consumed 2.002s CPU time.
Feb 12 03:59:23 volumio sudo[22187]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Feb 12 03:59:23 volumio volumio[21878]: info: Output device has changed, restarting Shairport Sync
Feb 12 03:59:23 volumio sudo[22187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:23 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:59:23 volumio sudo[22187]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:23 volumio sudo[22189]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 12 03:59:23 volumio volumio[21878]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 12 03:59:23 volumio sudo[22189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:23 volumio sudo[22191]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 12 03:59:23 volumio sudo[22191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:23 volumio sudo[22189]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 03:59:24 volumio sudo[22178]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:24 volumio sudo[22182]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:24 volumio sudo[22176]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:24 volumio go-librespot[22165]: time="2026-02-12T03:59:24-06:00" level=debug msg="obtained new client token: AAC4iNOb9EWDoKQ5+lv/itrsL42l+1PeWqjMQNha4xq4cENtNAa6uc2y0DSShitDg7nrIhmT6CUupqxfup++jF6CHbCbpUWk3rrt7Q8OHi31ThoxKri2B8psSWZ5DUBM+Shi7j2CLB9fr2lhPFfNsSWQCuBPX3UnGlraBrckBBedxjCUC3e0R0fnwr+10dwiM/nLvVeAQVMp12hgU7N3S6jxImnhzobYxrrkAR7WnYd77mkperBjoxs="
Feb 12 03:59:24 volumio go-librespot[22165]: time="2026-02-12T03:59:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:59:24 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 12 03:59:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 12 03:59:24 volumio systemd[1]: mpd.service: Consumed 1.645s CPU time.
Feb 12 03:59:24 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 12 03:59:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 12 03:59:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 12 03:59:24 volumio go-librespot[22165]: time="2026-02-12T03:59:24-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:24 volumio go-librespot[22165]: time="2026-02-12T03:59:24-06:00" level=debug msg="completed challenge"
Feb 12 03:59:24 volumio volumio[21878]: info: MPD Permissions set
Feb 12 03:59:24 volumio volumio[21878]: info: Shairport-Sync Started
Feb 12 03:59:24 volumio volumio[21878]: Error adding Membership: Error: addMembership EINVAL
Feb 12 03:59:24 volumio volumio[21878]: info: Shairport-Sync Started
Feb 12 03:59:24 volumio volumio[21878]: info: Shairport-Sync Started
Feb 12 03:59:24 volumio volumio[21878]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Feb 12 03:59:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 12 03:59:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 12 03:59:24 volumio go-librespot[22165]: time="2026-02-12T03:59:24-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 12 03:59:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:24 volumio sudo[22221]:  volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Feb 12 03:59:24 volumio sudo[22221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:24 volumio sudo[22221]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:24 volumio volumio[21878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload  || true
Feb 12 03:59:24 volumio sudo[22230]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Feb 12 03:59:24 volumio sudo[22230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::volumioGetState
Feb 12 03:59:24 volumio volumio[21878]: info: CorePlayQueue::getTrack 0
Feb 12 03:59:24 volumio sudo[22222]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 12 03:59:24 volumio sudo[22222]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 12 03:59:24 volumio sudo[22222]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:24 volumio volumio[21878]: info: Starting Shairport Sync
Feb 12 03:59:24 volumio systemd[1]: Reloading.
Feb 12 03:59:24 volumio sudo[22234]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 12 03:59:24 volumio sudo[22234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:24 volumio volumio[21878]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"}
Feb 12 03:59:24 volumio volumio[21878]: info: Spotify Successfully logged in
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 12 03:59:24 volumio volumio[21878]: info: [1770890364574] CoreMusicLibrary::Adding element Spotify
Feb 12 03:59:24 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 12 03:59:24 volumio volumio[21878]: Cannot find translation for source Bandcamp Discover
Feb 12 03:59:24 volumio volumio[21878]: Cannot find translation for source SoundCloud
Feb 12 03:59:24 volumio volumio[21878]: Cannot find translation for source YouTube2
Feb 12 03:59:24 volumio volumio[21878]: Cannot find translation for source YouTube Music
Feb 12 03:59:24 volumio volumio[21878]: Cannot find translation for source Podcast
Feb 12 03:59:24 volumio volumio[21878]: Cannot find translation for source Volusonic
Feb 12 03:59:24 volumio volumio[21878]: Cannot find translation for source Spotify
Feb 12 03:59:25 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:25 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:25 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 12 03:59:25 volumio volumio[21878]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 12 03:59:25 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 03:59:26 volumio volumio[21878]: info: go-librespot daemon successfully initialized
Feb 12 03:59:26 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 03:59:26 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Feb 12 03:59:27 volumio sudo[22230]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:27 volumio volumio[21878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:59:27 volumio sudo[22272]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:59:27 volumio sudo[22272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 12 03:59:27 volumio sudo[22272]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:27 volumio volumio[21878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Feb 12 03:59:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:27 volumio sudo[22276]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Feb 12 03:59:27 volumio go-librespot[22275]: go-librespot daemon starting...
Feb 12 03:59:27 volumio sudo[22276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 12 03:59:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 12 03:59:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 03:59:27 volumio systemd[1]: shairport-sync.service: Consumed 1.607s CPU time.
Feb 12 03:59:27 volumio go-librespot[22277]: time="2026-02-12T03:59:27-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:27 volumio go-librespot[22277]: time="2026-02-12T03:59:27-06:00" level=debug msg="app state loaded"
Feb 12 03:59:27 volumio go-librespot[22277]: time="2026-02-12T03:59:27-06:00" level=debug msg="stored credentials not found"
Feb 12 03:59:27 volumio go-librespot[22277]: time="2026-02-12T03:59:27-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:59:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 12 03:59:28 volumio sudo[22234]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:28 volumio volumio[21878]: info: Shairport-Sync Started
Feb 12 03:59:28 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-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 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-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 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-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 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-06:00" level=info msg="zeroconf server listening on port 34083"
Feb 12 03:59:28 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Feb 12 03:59:28 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 03:59:28 volumio sudo[22276]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-06:00" level=debug msg="obtained new client token: AADM1KDOgHYS9W9d5wwdw27hz3h1NueH+uRCWWi4b35mMleCPsjwQMOhRWExJai2OY6llMZHf/K0M3hl1zKDcnTtEIiCtQhToJvRtXGs75ilxu8nkvAXlBPSa1DticPuY1xLXe4mY85tKENEzFmtHhrxeKptUTYML6eQolOKzrmJurZQCWpz9e+yMoV2HDtPP3NIsUTMVnbGPd19p86xjIuL6+pzn034094lGX0usYX4i869d+lFn/PXQQ=="
Feb 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused"
Feb 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:443, retrying with a different AP" error="dial tcp 104.154.127.247:443: connect: connection refused"
Feb 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:80"
Feb 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-06:00" level=debug msg="completed challenge"
Feb 12 03:59:28 volumio go-librespot[22277]: time="2026-02-12T03:59:28-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 12 03:59:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:28 volumio volumio[21878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:59:28 volumio sudo[22301]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:59:28 volumio sudo[22301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:29 volumio sudo[22301]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:29 volumio volumio[21878]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Feb 12 03:59:29 volumio sudo[22305]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Feb 12 03:59:29 volumio sudo[22305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:29 volumio sudo[22305]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:29 volumio volumio[21878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Feb 12 03:59:29 volumio sudo[22308]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Feb 12 03:59:29 volumio sudo[22308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:29 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Feb 12 03:59:29 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Feb 12 03:59:29 volumio sudo[22308]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:29 volumio volumio[21878]: info: Initializing connection to go-librespot Websocket
Feb 12 03:59:29 volumio volumio[21878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:59:29 volumio volumio[21878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:59:29 volumio sudo[22315]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:59:29 volumio sudo[22315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:29 volumio sudo[22315]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:30 volumio volumio[21878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:59:30 volumio sudo[22318]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:59:30 volumio sudo[22318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:30 volumio sudo[22318]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:30 volumio mpd[22270]: 2026-02-12T03:59:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 12 03:59:31 volumio volumio[21878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:59:31 volumio sudo[22321]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:59:31 volumio sudo[22321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:31 volumio sudo[22321]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:31 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 12 03:59:31 volumio sudo[22107]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:31 volumio sudo[22097]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:31 volumio sudo[22191]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:31 volumio volumio[21878]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 03:59:31 volumio volumio[21878]:   assert.ok(self.idling)
Feb 12 03:59:31 volumio volumio[21878]: error: The expression evaluated to a falsy value:
Feb 12 03:59:31 volumio volumio[21878]:   assert.ok(self.idling)
Feb 12 03:59:31 volumio volumio[21878]: error: MPD error: The expression evaluated to a falsy value:
Feb 12 03:59:31 volumio volumio[21878]:   assert.ok(self.idling)
Feb 12 03:59:31 volumio volumio[21878]: error: The expression evaluated to a falsy value:
Feb 12 03:59:31 volumio volumio[21878]:   assert.ok(self.idling)
Feb 12 03:59:31 volumio volumio[21878]: info: MPD running with PID22270
Feb 12 03:59:31 volumio volumio[21878]:  ,establishing connection
Feb 12 03:59:31 volumio volumio[21878]: error: updateQueue error: null
Feb 12 03:59:31 volumio volumio[21878]: error: updateQueue error: null
Feb 12 03:59:31 volumio volumio[21878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:59:31 volumio sudo[22328]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:59:31 volumio sudo[22328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:31 volumio sudo[22328]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 12 03:59:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:31 volumio go-librespot[22330]: go-librespot daemon starting...
Feb 12 03:59:31 volumio go-librespot[22331]: time="2026-02-12T03:59:31-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:31 volumio go-librespot[22331]: time="2026-02-12T03:59:31-06:00" level=debug msg="app state loaded"
Feb 12 03:59:31 volumio go-librespot[22331]: time="2026-02-12T03:59:31-06:00" level=debug msg="stored credentials not found"
Feb 12 03:59:31 volumio go-librespot[22331]: time="2026-02-12T03:59:31-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:59:32 volumio go-librespot[22331]: time="2026-02-12T03:59:32-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 12 03:59:32 volumio go-librespot[22331]: time="2026-02-12T03:59:32-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 12 03:59:32 volumio go-librespot[22331]: time="2026-02-12T03:59:32-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 12 03:59:32 volumio go-librespot[22331]: time="2026-02-12T03:59:32-06:00" level=info msg="zeroconf server listening on port 39387"
Feb 12 03:59:32 volumio kernel: hwmon hwmon1: Voltage normalised
Feb 12 03:59:32 volumio go-librespot[22331]: time="2026-02-12T03:59:32-06:00" level=debug msg="obtained new client token: AACgZnONYXgij/rFne5Qih2Jw8JXn9MuRc/7zL9BKtHI0N+joDu36GYelzDgRcAM1PRysXSTvmn+y0GDDMUaoP3JtOr8De7AlT6iLf0sFYRVx8mAUxX8VoI5clXGAtwtoG9nJdojmHXLXl9Rl/pUh+TfVJVtjRqBtu7cCfGfkniih+AkpCvxFWWpw5Mq9WZQ5EuecyBELf1w7nW+VfxXYEBFD3wtIwCW06RPqWTxs3BKnP6JYWKmMaY="
Feb 12 03:59:32 volumio volumio[21878]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 12 03:59:32 volumio sudo[22340]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 12 03:59:32 volumio sudo[22340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:32 volumio go-librespot[22331]: time="2026-02-12T03:59:32-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:59:32 volumio sudo[22340]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:32 volumio volumio[21878]: info: Completed starting Core Plugins
Feb 12 03:59:32 volumio volumio[21878]: info: -------------------------------------------
Feb 12 03:59:32 volumio volumio[21878]: info: -----    MyVolumio plugins startup     ----
Feb 12 03:59:32 volumio volumio[21878]: info: -------------------------------------------
Feb 12 03:59:32 volumio volumio[21878]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 12 03:59:32 volumio go-librespot[22331]: time="2026-02-12T03:59:32-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:32 volumio go-librespot[22331]: time="2026-02-12T03:59:32-06:00" level=debug msg="completed challenge"
Feb 12 03:59:32 volumio go-librespot[22331]: time="2026-02-12T03:59:32-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 12 03:59:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:32 volumio volumio[21878]: info: Initializing connection to go-librespot Websocket
Feb 12 03:59:32 volumio volumio[21878]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:59:34 volumio sudo[22346]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 03:59:34 volumio sudo[22346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:34 volumio sudo[22348]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 03:59:34 volumio sudo[22348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:34 volumio sudo[22351]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 12 03:59:34 volumio sudo[22351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 12 03:59:34 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Feb 12 03:59:34 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Feb 12 03:59:34 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Feb 12 03:59:34 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Feb 12 03:59:34 volumio sudo[22351]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:34 volumio sudo[22348]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:34 volumio sudo[22346]: pam_unix(sudo:session): session closed for user root
Feb 12 03:59:34 volumio mpd_monitor.sh[22354]: MPD Monitor Service: Starting MPD Monitor Service
Feb 12 03:59:34 volumio volumio[21878]: info: Successfully started MPD Monitor
Feb 12 03:59:34 volumio volumio[21878]: info: Successfully started MPD Monitor
Feb 12 03:59:34 volumio volumio[21878]: info: Successfully started MPD Monitor
Feb 12 03:59:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 12 03:59:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:35 volumio go-librespot[22358]: go-librespot daemon starting...
Feb 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59:35-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59:35-06:00" level=debug msg="app state loaded"
Feb 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59:35-06:00" level=debug msg="stored credentials not found"
Feb 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59:35-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:59:35 volumio volumio[21878]: info: Initializing connection to go-librespot Websocket
Feb 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59:35-06:00" level=debug msg="new websocket client"
Feb 12 03:59:35 volumio volumio[21878]: info: Connection to go-librespot Websocket established
Feb 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59: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-gew4.spotify.com:80]"
Feb 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59:35-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 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59:35-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 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59:35-06:00" level=info msg="zeroconf server listening on port 41749"
Feb 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59:35-06:00" level=debug msg="obtained new client token: AAAvDZ8pT8kFmLNWmHizUegH2TXRh+o7swGzNJm26py/s4G9QMzfdcM+f8fvrW94l95p4JZy/sB0OiT235lYG55d4JRnifKULwxyuzIQmlCc3UGcduVMQGzD0afr+KDd9EFXpSjqdBuPxJkT9HRvIjcq/i34a6PyFsvOLixO+z6aF3cHb3xj+W7fvHgLvWzVSw8Gcba8PjzdrdElkYdOqK+asFPvOQtYP1PdQfiY4HfGEq55fnEQxnwsMQ=="
Feb 12 03:59:35 volumio go-librespot[22359]: time="2026-02-12T03:59:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:59:36 volumio go-librespot[22359]: time="2026-02-12T03:59:36-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:36 volumio go-librespot[22359]: time="2026-02-12T03:59:36-06:00" level=debug msg="completed challenge"
Feb 12 03:59:36 volumio go-librespot[22359]: time="2026-02-12T03:59:36-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 12 03:59:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:36 volumio volumio[21878]: info: Connection to go-librespot Websocket closed
Feb 12 03:59:38 volumio kernel: hwmon hwmon1: Undervoltage detected!
Feb 12 03:59:38 volumio volumio[21878]: info: Getting Spotify volume
Feb 12 03:59:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 12 03:59:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 12 03:59:39 volumio go-librespot[22382]: go-librespot daemon starting...
Feb 12 03:59:39 volumio go-librespot[22383]: time="2026-02-12T03:59:39-06:00" level=info msg="running go-librespot 0.4.0"
Feb 12 03:59:39 volumio go-librespot[22383]: time="2026-02-12T03:59:39-06:00" level=debug msg="app state loaded"
Feb 12 03:59:39 volumio go-librespot[22383]: time="2026-02-12T03:59:39-06:00" level=debug msg="stored credentials not found"
Feb 12 03:59:39 volumio go-librespot[22383]: time="2026-02-12T03:59:39-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 12 03:59:39 volumio go-librespot[22383]: time="2026-02-12T03:59: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 12 03:59:39 volumio go-librespot[22383]: time="2026-02-12T03:59:39-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 12 03:59:39 volumio go-librespot[22383]: time="2026-02-12T03:59:39-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 12 03:59:39 volumio go-librespot[22383]: time="2026-02-12T03:59:39-06:00" level=info msg="zeroconf server listening on port 39755"
Feb 12 03:59:39 volumio go-librespot[22383]: time="2026-02-12T03:59:39-06:00" level=debug msg="obtained new client token: AADjfdTjZ1LzaUY+Og2gFlorwi6HYqu7bvlqS/7h76gEcG/3Qdze34jUbZUEr8x+5daDiTT2zoyuaV1P4Tjo2UXPBjx+pGnKTIG1EnoAfAgVBF9c7BSQMTeKf3qBWkJA3wpyrMrvbzGMGCiGa2JY9PiGusA1DEmCFlMIZ0cazE9RQGHCYKVCXuiR8IvkTM2RNQPdmBhPVJR9cYl9ldALX2MZMTXvV2+jLeHljhqSK7CLlcsGsWGom8LX2w=="
Feb 12 03:59:40 volumio go-librespot[22383]: time="2026-02-12T03:59:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 12 03:59:40 volumio go-librespot[22383]: time="2026-02-12T03:59:40-06:00" level=debug msg="completed keyexchange"
Feb 12 03:59:40 volumio go-librespot[22383]: time="2026-02-12T03:59:40-06:00" level=debug msg="completed challenge"
Feb 12 03:59:40 volumio go-librespot[22383]: time="2026-02-12T03:59:40-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 12 03:59:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 03:59:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 12 03:59:40 volumio volumio[21878]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 03:59:40 volumio volumio[21878]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 12 03:59:40 volumio volumio[21878]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 12 03:59:40 volumio volumio[21878]:   errno: -111,
Feb 12 03:59:40 volumio volumio[21878]:   code: 'ECONNREFUSED',
Feb 12 03:59:40 volumio volumio[21878]:   syscall: 'connect',
Feb 12 03:59:40 volumio volumio[21878]:   address: '127.0.0.1',
Feb 12 03:59:40 volumio volumio[21878]:   port: 9879,
Feb 12 03:59:40 volumio volumio[21878]:   response: undefined
Feb 12 03:59:40 volumio volumio[21878]: }
Feb 12 03:59:40 volumio volumio[21878]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 12 03:59:41 volumio sudo[22404]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 03:58'
Feb 12 03:59:41 volumio sudo[22404]: 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"