Jan 12 23:44:00 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Jan 12 23:44:00 volumio sudo[2895]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:00 volumio sudo[2897]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:00 volumio sudo[2893]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:00 volumio volumio[2281]: info: Successfully started MPD Monitor
Jan 12 23:44:00 volumio mpd_monitor.sh[2901]: MPD Monitor Service: Starting MPD Monitor Service
Jan 12 23:44:00 volumio volumio[2281]: info: Successfully started MPD Monitor
Jan 12 23:44:00 volumio volumio[2281]: info: Successfully started MPD Monitor
Jan 12 23:44:01 volumio volumio[2281]: info: Initializing connection to go-librespot Websocket
Jan 12 23:44:01 volumio volumio[2281]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jan 12 23:44:01 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.55.51
Jan 12 23:44:01 volumio avahi-daemon[664]: Registering new address record for 169.254.55.51 on eth0.IPv4.
Jan 12 23:44:01 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:44:01 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:01 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:01 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:01 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.55.51
Jan 12 23:44:01 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.55.51
Jan 12 23:44:01 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.55.51
Jan 12 23:44:01 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:44:01 volumio avahi-daemon[664]: Withdrawing address record for 169.254.55.51 on eth0.
Jan 12 23:44:01 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:44:01 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:01 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:01 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37.
Jan 12 23:44:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:03 volumio go-librespot[2937]: go-librespot daemon starting...
Jan 12 23:44:03 volumio go-librespot[2938]: time="2026-01-12T23:44:03-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:03 volumio kernel: hwmon hwmon1: Undervoltage detected!
Jan 12 23:44:03 volumio go-librespot[2938]: time="2026-01-12T23:44:03-06:00" level=debug msg="app state loaded"
Jan 12 23:44:03 volumio go-librespot[2938]: time="2026-01-12T23:44:03-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:03 volumio go-librespot[2938]: time="2026-01-12T23:44:03-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:03 volumio go-librespot[2938]: time="2026-01-12T23:44: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]"
Jan 12 23:44:03 volumio go-librespot[2938]: time="2026-01-12T23:44: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]"
Jan 12 23:44:03 volumio go-librespot[2938]: time="2026-01-12T23:44: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]"
Jan 12 23:44:03 volumio go-librespot[2938]: time="2026-01-12T23:44:03-06:00" level=info msg="zeroconf server listening on port 43385"
Jan 12 23:44:04 volumio go-librespot[2938]: time="2026-01-12T23:44:04-06:00" level=debug msg="obtained new client token: AAAyZGENYxfzgx8QNiYXSA4ziOW+MmsFvJQvNGmdkHU4hRF9Nb5hhW+lx9ThMUIpUE66DWlZJEcziLm1Zn51XetW8eQRXRlfQWSYHOmwRj2EV4lgOtzJnsu7ypjlgNrSDMLY5rWCW4Kq05MKD6oLhYD1U15tF3IbP3gKl23rOJG71EWv5rw8coxTJtQdpm6D6zxJbsdBEYoklVNaNm80KCj5Ni6+VusjnJdCJCrJRvzW4JrovCgHBocxaQ=="
Jan 12 23:44:04 volumio go-librespot[2938]: time="2026-01-12T23:44:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:04 volumio go-librespot[2938]: time="2026-01-12T23:44:04-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:04 volumio go-librespot[2938]: time="2026-01-12T23:44:04-06:00" level=debug msg="completed challenge"
Jan 12 23:44:04 volumio go-librespot[2938]: time="2026-01-12T23:44:04-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 "
Jan 12 23:44:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:04 volumio volumio[2281]: info: Initializing connection to go-librespot Websocket
Jan 12 23:44:06 volumio volumio[2281]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jan 12 23:44:06 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.94.90
Jan 12 23:44:06 volumio avahi-daemon[664]: Registering new address record for 169.254.94.90 on eth0.IPv4.
Jan 12 23:44:06 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:44:07 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:07 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:07 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38.
Jan 12 23:44:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:07 volumio go-librespot[2978]: go-librespot daemon starting...
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-06:00" level=debug msg="app state loaded"
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:07 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.94.90
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-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]"
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-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]"
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-06:00" level=info msg="zeroconf server listening on port 34599"
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Jan 12 23:44:07 volumio volumio[2281]: info: Adding plugin bluetooth to MyMusic Plugins
Jan 12 23:44:07 volumio volumio[2281]: info: Adding plugin multiroom to MyMusic Plugins
Jan 12 23:44:07 volumio volumio[2281]: info: Adding plugin metavolumio to MyMusic Plugins
Jan 12 23:44:07 volumio volumio[2281]: info: Adding plugin cd_controller to MyMusic Plugins
Jan 12 23:44:07 volumio volumio[2281]: info: Adding plugin qobuzconnect to MyMusic Plugins
Jan 12 23:44:07 volumio volumio[2281]: info: Adding plugin smart_inputs to MyMusic Plugins
Jan 12 23:44:07 volumio volumio[2281]: info: Adding plugin tidalconnect to MyMusic Plugins
Jan 12 23:44:07 volumio volumio[2281]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-06:00" level=debug msg="obtained new client token: AADpuVSlrAGJz5JhJwVfhQNTHT0F7J7ZfCP19WVYEzXqYS3pdreFqq79MJe0tROppCK5utyN64qKJRnYAjNgAWmUYxEZL8jEoeZszSitjsZgaqr6YZJy1ccTmjR4R5C3BEHKC9LdsN+njBP7GmR18er1mhtygUUPDKIxkgpaS6YuGU8q3j3Mr9jIaFyzgrbERhfRt65kNpwBSRHMwQmbIS/DUKYWy9jB3FAfd1hKY4FrJuggR7vD8VdOfA=="
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44:07-06:00" level=debug msg="completed challenge"
Jan 12 23:44:07 volumio go-librespot[2979]: time="2026-01-12T23:44: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 "
Jan 12 23:44:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:08 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.94.90
Jan 12 23:44:08 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.94.90
Jan 12 23:44:08 volumio avahi-daemon[664]: Withdrawing address record for 169.254.94.90 on eth0.
Jan 12 23:44:08 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:44:08 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:08 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:44:08 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:08 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:08 volumio volumio[2281]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Jan 12 23:44:08 volumio volumio[2281]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Jan 12 23:44:08 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:08 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:08 volumio volumio[2281]: info: Starting MyVolumio Remote Streaming Endpoints
Jan 12 23:44:08 volumio volumio[2281]: info: MyVolumio login type: Token
Jan 12 23:44:08 volumio volumio[2281]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Jan 12 23:44:08 volumio volumio[2281]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Jan 12 23:44:09 volumio kernel: hwmon hwmon1: Voltage normalised
Jan 12 23:44:09 volumio volumio[2281]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Jan 12 23:44:09 volumio volumio[2281]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Jan 12 23:44:09 volumio volumio[2281]: info: Streaming services startup
Jan 12 23:44:09 volumio volumio[2281]: info: Starting Streaming Daemon
Jan 12 23:44:09 volumio sudo[3004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Jan 12 23:44:09 volumio sudo[3004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:09 volumio volumio[2281]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Jan 12 23:44:09 volumio sudo[3004]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:09 volumio volumio[2281]: info: Initializing connection to go-librespot Websocket
Jan 12 23:44:09 volumio volumio[2281]: error: Cannot start Volumio Streaming Daemon
Jan 12 23:44:09 volumio volumio[2281]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Jan 12 23:44:09 volumio volumio[2281]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Jan 12 23:44:09 volumio volumio[2281]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jan 12 23:44:10 volumio volumio[2281]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Jan 12 23:44:10 volumio volumio[2281]: info: MyVolumio token set successfully
Jan 12 23:44:10 volumio volumio[2281]: info: MYVOLUMIO: Adding device
Jan 12 23:44:10 volumio volumio[2281]: info: MYVOLUMIO: Evaluating Server
Jan 12 23:44:10 volumio volumio[2281]: info: MyVolumio status changed
Jan 12 23:44:10 volumio volumio[2281]: info: Streaming services startup
Jan 12 23:44:10 volumio volumio[2281]: info: Starting Streaming Daemon
Jan 12 23:44:10 volumio volumio[2281]: info: Removing browser output: myVolumio user plan is not superstar
Jan 12 23:44:10 volumio volumio[2281]: info: Removing audio output:
Jan 12 23:44:10 volumio volumio[2281]: info: Stoppping Tunnel 1
Jan 12 23:44:10 volumio sudo[3032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Jan 12 23:44:10 volumio sudo[3032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:10 volumio sudo[3034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Jan 12 23:44:10 volumio sudo[3034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:10 volumio sudo[3032]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:10 volumio volumio[2281]: error: Cannot start Volumio Streaming Daemon
Jan 12 23:44:10 volumio volumio[2281]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Jan 12 23:44:10 volumio volumio[2281]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Jan 12 23:44:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jan 12 23:44:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jan 12 23:44:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jan 12 23:44:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jan 12 23:44:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jan 12 23:44:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jan 12 23:44:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jan 12 23:44:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Jan 12 23:44:10 volumio sudo[3034]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:10 volumio volumio[2281]: info: Remote SSH Stopped
Jan 12 23:44:10 volumio volumio[2281]: info: Setting Geolocation for MyVolumio to us4
Jan 12 23:44:10 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:10 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:10 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:11 volumio volumio[2281]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Jan 12 23:44:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39.
Jan 12 23:44:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:11 volumio go-librespot[3037]: go-librespot daemon starting...
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44:11-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44:11-06:00" level=debug msg="app state loaded"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44:11-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44:11-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44: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]"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44: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]"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44: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]"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44:11-06:00" level=info msg="zeroconf server listening on port 36967"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44:11-06:00" level=debug msg="obtained new client token: AADV2L3c0TFphAyCmyOTu0VnXgRj6GZFrmmdZElCoIQHkVQFhZwScYyvZWMfgLvu0hj5ZXx+oE6AUBY02JVRiFjXRqGxSl9dJdwPUvpwlqi1seL/iocmxxg89Clb2uO7fH8hxrif+UQyMp4KYXkoJI0H2R0loNa+CMGuexxqdCLRz+SYeI7qHGzgcfUIX8/A6EVXgpHlZEcsr0XxRBsM3kDlAv3erodK93Mbij109jMNHW8KAuhFSFQhaQ=="
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44:11-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44:11-06:00" level=debug msg="completed challenge"
Jan 12 23:44:11 volumio go-librespot[3038]: time="2026-01-12T23:44: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 "
Jan 12 23:44:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:11 volumio volumio[2281]: info: Updating MyVolumio device info
Jan 12 23:44:11 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:11 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:11 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:12 volumio volumio[2281]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Jan 12 23:44:12 volumio volumio[2281]: info: Initializing connection to go-librespot Websocket
Jan 12 23:44:12 volumio volumio[2281]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jan 12 23:44:13 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.170.214
Jan 12 23:44:13 volumio avahi-daemon[664]: Registering new address record for 169.254.170.214 on eth0.IPv4.
Jan 12 23:44:13 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:44:13 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:13 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:13 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.170.214
Jan 12 23:44:14 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.170.214
Jan 12 23:44:14 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.170.214
Jan 12 23:44:14 volumio avahi-daemon[664]: Withdrawing address record for 169.254.170.214 on eth0.
Jan 12 23:44:14 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:44:14 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:14 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:14 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:14 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:44:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40.
Jan 12 23:44:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:14 volumio go-librespot[3091]: go-librespot daemon starting...
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-06:00" level=debug msg="app state loaded"
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:15 volumio volumio[2281]: info: MYVOLUMIO: Adding device
Jan 12 23:44:15 volumio volumio[2281]: info: MYVOLUMIO: Evaluating Server
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-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]"
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-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]"
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-06:00" level=info msg="zeroconf server listening on port 38605"
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-06:00" level=debug msg="obtained new client token: AADQUrlNNMgREzqswbgwtefdV7XgjmlRm7TdFkbKHLlVa8vMds5Zy6cYASC7f9cOLog49tCt/vh4+kIVahkxgtpauWYSvy0IGB2euHd6sqt1PmB88Mk/M92nd9GHN+z5F0P4i1cf8lJf51PJhvQehnezUbfZMP0u8vKIjDBMYWq9Wmj7+j3OcjsPRqM00q664LslToe+yaFbPqY+LKisTcA3uIO3Nz4ElOuecSNnf3TJqM3AK0SLRqmE0Q=="
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44:15-06:00" level=debug msg="completed challenge"
Jan 12 23:44:15 volumio go-librespot[3092]: time="2026-01-12T23:44: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 "
Jan 12 23:44:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:15 volumio volumio[2281]: info: Setting Geolocation for MyVolumio to us4
Jan 12 23:44:15 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:15 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:15 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:15 volumio volumio[2281]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Jan 12 23:44:15 volumio volumio[2281]: info: Initializing connection to go-librespot Websocket
Jan 12 23:44:15 volumio volumio[2281]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jan 12 23:44:16 volumio volumio[2281]: info: Updating MyVolumio device info
Jan 12 23:44:16 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:16 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:16 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:16 volumio volumio[2281]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Jan 12 23:44:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41.
Jan 12 23:44:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:18 volumio go-librespot[3117]: go-librespot daemon starting...
Jan 12 23:44:18 volumio go-librespot[3118]: time="2026-01-12T23:44:18-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:18 volumio go-librespot[3118]: time="2026-01-12T23:44:18-06:00" level=debug msg="app state loaded"
Jan 12 23:44:18 volumio go-librespot[3118]: time="2026-01-12T23:44:18-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:18 volumio go-librespot[3118]: time="2026-01-12T23:44:18-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:18 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.160.160
Jan 12 23:44:18 volumio avahi-daemon[664]: Registering new address record for 169.254.160.160 on eth0.IPv4.
Jan 12 23:44:18 volumio volumio[2281]: info: Initializing connection to go-librespot Websocket
Jan 12 23:44:18 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:44:18 volumio go-librespot[3118]: time="2026-01-12T23:44:18-06:00" level=debug msg="new websocket client"
Jan 12 23:44:18 volumio volumio[2281]: info: Connection to go-librespot Websocket established
Jan 12 23:44:18 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:18 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:18 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:19 volumio go-librespot[3118]: time="2026-01-12T23:44: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Jan 12 23:44:19 volumio go-librespot[3118]: time="2026-01-12T23:44:19-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]"
Jan 12 23:44:19 volumio go-librespot[3118]: time="2026-01-12T23:44:19-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]"
Jan 12 23:44:19 volumio go-librespot[3118]: time="2026-01-12T23:44:19-06:00" level=info msg="zeroconf server listening on port 33265"
Jan 12 23:44:19 volumio go-librespot[3118]: time="2026-01-12T23:44:19-06:00" level=debug msg="obtained new client token: AAAXeV7b6ck09QPTkuV98zykc4BTlRcsPKq+a2LJO4R671IXaa519uMXkDV2tn2pic3X0thTizQi0OjUWGzwD3tE7mKOnUtWiROmK5PW960IGszDHPNtCAr8jpG+im3kUcKrQC8zQIuEgXbLRp4/ofpULYdnwkyX5hp/lxxulmNwgiLCrYdOTn+zge4FjfopWHBjN8y7QYbpveyeZXkVGVTNitgoX23IVykUGLnpONSblTMj6MgirLY="
Jan 12 23:44:19 volumio go-librespot[3118]: time="2026-01-12T23:44:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:19 volumio go-librespot[3118]: time="2026-01-12T23:44:19-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:19 volumio go-librespot[3118]: time="2026-01-12T23:44:19-06:00" level=debug msg="completed challenge"
Jan 12 23:44:19 volumio go-librespot[3118]: time="2026-01-12T23:44: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 "
Jan 12 23:44:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:19 volumio volumio[2281]: info: Connection to go-librespot Websocket closed
Jan 12 23:44:19 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.160.160
Jan 12 23:44:19 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.160.160
Jan 12 23:44:19 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.160.160
Jan 12 23:44:19 volumio avahi-daemon[664]: Withdrawing address record for 169.254.160.160 on eth0.
Jan 12 23:44:19 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:44:20 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:20 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:20 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:44:20 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:21 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jan 12 23:44:21 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:21 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Jan 12 23:44:21 volumio volumio-remote-updater[14193]: Test mode disabled
Jan 12 23:44:21 volumio volumio-remote-updater[14193]: Alpha mode disabled
Jan 12 23:44:21 volumio volumio-remote-updater[14193]: Alpha legacy test mode disabled
Jan 12 23:44:21 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Jan 12 23:44:21 volumio volumio[2281]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"ANNOUNCEMENT
\n\n- Production line
\n
\nFIX
\n\n- Nodejs 20.5.1 version pinning with static package fallback
\n
\n","title":"Update v4.073","updateavailable":true}
Jan 12 23:44:21 volumio volumio[2281]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Jan 12 23:44:21 volumio volumio[2281]: info: Getting Spotify volume
Jan 12 23:44:21 volumio volumio[2281]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jan 12 23:44:21 volumio volumio[2281]: Error: connect ECONNREFUSED 127.0.0.1:9879
Jan 12 23:44:21 volumio volumio[2281]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Jan 12 23:44:21 volumio volumio[2281]: errno: -111,
Jan 12 23:44:21 volumio volumio[2281]: code: 'ECONNREFUSED',
Jan 12 23:44:21 volumio volumio[2281]: syscall: 'connect',
Jan 12 23:44:21 volumio volumio[2281]: address: '127.0.0.1',
Jan 12 23:44:21 volumio volumio[2281]: port: 9879,
Jan 12 23:44:21 volumio volumio[2281]: response: undefined
Jan 12 23:44:21 volumio volumio[2281]: }
Jan 12 23:44:21 volumio volumio[2281]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jan 12 23:44:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42.
Jan 12 23:44:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:22 volumio go-librespot[3176]: go-librespot daemon starting...
Jan 12 23:44:22 volumio go-librespot[3177]: time="2026-01-12T23:44:22-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:22 volumio go-librespot[3177]: time="2026-01-12T23:44:22-06:00" level=debug msg="app state loaded"
Jan 12 23:44:22 volumio go-librespot[3177]: time="2026-01-12T23:44:22-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:22 volumio go-librespot[3177]: time="2026-01-12T23:44:22-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:22 volumio sudo[3185]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-12 23:43'
Jan 12 23:44:22 volumio sudo[3185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:22 volumio sudo[3185]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:22 volumio go-librespot[3177]: time="2026-01-12T23:44:22-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]"
Jan 12 23:44:22 volumio go-librespot[3177]: time="2026-01-12T23:44:22-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]"
Jan 12 23:44:22 volumio go-librespot[3177]: time="2026-01-12T23:44:22-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]"
Jan 12 23:44:22 volumio go-librespot[3177]: time="2026-01-12T23:44:22-06:00" level=info msg="zeroconf server listening on port 36945"
Jan 12 23:44:22 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:22 volumio volumio-remote-updater[14193]: [2026-01-12 23:44:22] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Jan 12 23:44:22 volumio volumio-remote-updater[14193]: [2026-01-12 23:44:22] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Jan 12 23:44:23 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Jan 12 23:44:23 volumio systemd[1]: volumio.service: Consumed 55.161s CPU time.
Jan 12 23:44:23 volumio go-librespot[3177]: time="2026-01-12T23:44:23-06:00" level=debug msg="obtained new client token: AADNWURw3vyUoA2g0BpxzYY6NYVt1JM7jcpkQ/fTwGzpTpxbKMYRM7kb2IQgMRFWVHimNQp5bQtessoeV9kOdoU3ZuvtboJcXppFMoRs31X41RLqBMXH+X88WTCqkHgzVB5PX3wg4ynDPCAvgNGOZah7B0fwedDqV6FLuy4cBA4qmll6XVLMEBNkYxTczHuC0mlnqv2AZZ0IjIVj4XJ6E+ZSAD8SB4dSIhKgwusz1yFhp6g6Na/oCl0="
Jan 12 23:44:23 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Jan 12 23:44:23 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Jan 12 23:44:23 volumio go-librespot[3177]: time="2026-01-12T23:44:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:23 volumio go-librespot[3177]: time="2026-01-12T23:44:23-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:23 volumio go-librespot[3177]: time="2026-01-12T23:44:23-06:00" level=debug msg="completed challenge"
Jan 12 23:44:23 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22156.
Jan 12 23:44:23 volumio go-librespot[3177]: time="2026-01-12T23:44:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Jan 12 23:44:23 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Jan 12 23:44:23 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Jan 12 23:44:23 volumio systemd[1]: volumio.service: Consumed 55.161s CPU time.
Jan 12 23:44:23 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Jan 12 23:44:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:23 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Jan 12 23:44:25 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.8.246
Jan 12 23:44:25 volumio avahi-daemon[664]: Registering new address record for 169.254.8.246 on eth0.IPv4.
Jan 12 23:44:25 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:44:25 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:25 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:25 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:25 volumio volumio[3198]: info: -------------------------------------------
Jan 12 23:44:25 volumio volumio[3198]: info: ----- Volumio3 ----
Jan 12 23:44:25 volumio volumio[3198]: info: -------------------------------------------
Jan 12 23:44:25 volumio volumio[3198]: info: ----- System startup ----
Jan 12 23:44:25 volumio volumio[3198]: info: -------------------------------------------
Jan 12 23:44:25 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.8.246
Jan 12 23:44:25 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.8.246
Jan 12 23:44:25 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.8.246
Jan 12 23:44:25 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:44:25 volumio avahi-daemon[664]: Withdrawing address record for 169.254.8.246 on eth0.
Jan 12 23:44:25 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:25 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:25 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:25 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:44:26 volumio volumio[3198]: info: MYVOLUMIO Environment detected
Jan 12 23:44:26 volumio volumio[3198]: info: Plugin folders cleanup
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning into folder /volumio/app/plugins/
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category audio_interface
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category miscellanea
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category music_service
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category plugins.json
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category system_controller
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category user_interface
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning into folder /data/plugins/
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category audio_interface
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category music_service
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category system_controller
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category system_hardware
Jan 12 23:44:26 volumio volumio[3198]: info: Scanning category user_interface
Jan 12 23:44:26 volumio volumio[3198]: info: Plugin folders cleanup completed
Jan 12 23:44:26 volumio volumio[3198]: info: -------------------------------------------
Jan 12 23:44:26 volumio volumio[3198]: info: ----- Core plugins startup ----
Jan 12 23:44:26 volumio volumio[3198]: info: -------------------------------------------
Jan 12 23:44:26 volumio volumio[3198]: info: Loading plugins from folder /volumio/app/plugins/
Jan 12 23:44:26 volumio volumio[3198]: info: Adding plugin upnp to MyMusic Plugins
Jan 12 23:44:26 volumio volumio[3198]: info: Adding plugin airplay_emulation to MyMusic Plugins
Jan 12 23:44:26 volumio volumio[3198]: info: Adding plugin upnp_browser to MyMusic Plugins
Jan 12 23:44:26 volumio volumio[3198]: info: Loading plugins from folder /data/plugins/
Jan 12 23:44:26 volumio volumio[3198]: info: Loading plugin "system"...
Jan 12 23:44:26 volumio volumio[3198]: info: Loading plugin "appearance"...
Jan 12 23:44:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43.
Jan 12 23:44:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:26 volumio go-librespot[3257]: go-librespot daemon starting...
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-06:00" level=debug msg="app state loaded"
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-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]"
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-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]"
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-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]"
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-06:00" level=info msg="zeroconf server listening on port 44781"
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-06:00" level=debug msg="obtained new client token: AAC42Aa80gB0BxUDMLjSVBGu5wgxbC8Q7hKz+eu+7FNWxtE8V5WTAxRdOkfsnVEKkIh6+5H2+UNWT6nhgvnsfN6rmKwkux2P8kyx+/g42j5f1q0/9WimiUUb4DCc1B04qeTHq8Ji/+GlGZZ8qkLfihDWECLVJlwyReZfGoBBF1S+iakmAksL/wjusPWQgvsQuhWiSQ/L+pqm1jigWFjF1nW2WCkc67yYMU3dUlygLLQAIQM4u+fb3I7PjA=="
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:26 volumio go-librespot[3259]: time="2026-01-12T23:44:26-06:00" level=debug msg="completed challenge"
Jan 12 23:44:27 volumio go-librespot[3259]: time="2026-01-12T23:44:27-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Jan 12 23:44:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:27 volumio volumio[3198]: info: Loading plugin "network"...
Jan 12 23:44:27 volumio volumio[3198]: info: Refreshing Cached IP Addresses
Jan 12 23:44:27 volumio sudo[3268]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jan 12 23:44:27 volumio sudo[3268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:27 volumio sudo[3270]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 12 23:44:27 volumio sudo[3270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:27 volumio sudo[3268]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:27 volumio sudo[3270]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:27 volumio volumio[3198]: info: Loading plugin "services"...
Jan 12 23:44:27 volumio volumio[3198]: info: Loading plugin "alsa_controller"...
Jan 12 23:44:27 volumio sudo[3281]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Jan 12 23:44:27 volumio sudo[3281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:27 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jan 12 23:44:27 volumio volumio[3198]: info: Loading plugin "wizard"...
Jan 12 23:44:27 volumio volumio[3198]: info: Loading plugin "networkfs"...
Jan 12 23:44:27 volumio volumio[3198]: info: Starting Udev Watcher for removable devices
Jan 12 23:44:27 volumio volumio[3198]: info: Ignoring mount for partition: boot
Jan 12 23:44:27 volumio volumio[3198]: info: Ignoring mount for partition: volumio
Jan 12 23:44:27 volumio volumio[3198]: info: Ignoring mount for partition: volumio_data
Jan 12 23:44:27 volumio volumio[3198]: info: Mounting Device Wikipedia
Jan 12 23:44:27 volumio sudo[3307]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Jan 12 23:44:27 volumio sudo[3307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:27 volumio sudo[3307]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:27 volumio volumio[3198]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Jan 12 23:44:27 volumio volumio[3198]: dmesg(1) may have more information after failed mount system call.
Jan 12 23:44:27 volumio volumio[3198]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Jan 12 23:44:27 volumio volumio[3198]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Jan 12 23:44:27 volumio volumio[3198]: dmesg(1) may have more information after failed mount system call.
Jan 12 23:44:27 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jan 12 23:44:27 volumio volumio[3198]: info: Loading plugin "volumio_command_line_client"...
Jan 12 23:44:27 volumio volumio[3198]: info: Loading plugin "upnp"...
Jan 12 23:44:27 volumio volumio[3198]: info: [1768283067752] Starting Upmpd Daemon
Jan 12 23:44:27 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jan 12 23:44:27 volumio volumio[3198]: info: Loading plugin "my_music"...
Jan 12 23:44:27 volumio volumio[3198]: info: Loading plugin "mpd"...
Jan 12 23:44:27 volumio sudo[3281]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:27 volumio volumio-remote-updater[14193]: [2026-01-12 23:44:27] [connect] Successful connection
Jan 12 23:44:28 volumio kernel: hwmon hwmon1: Undervoltage detected!
Jan 12 23:44:28 volumio volumio[3198]: info: Loading plugin "upnp_browser"...
Jan 12 23:44:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44.
Jan 12 23:44:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:30 volumio go-librespot[3310]: go-librespot daemon starting...
Jan 12 23:44:30 volumio go-librespot[3311]: time="2026-01-12T23:44:30-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:30 volumio go-librespot[3311]: time="2026-01-12T23:44:30-06:00" level=debug msg="app state loaded"
Jan 12 23:44:30 volumio go-librespot[3311]: time="2026-01-12T23:44:30-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:30 volumio go-librespot[3311]: time="2026-01-12T23:44:30-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:30 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.139.214
Jan 12 23:44:30 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:44:30 volumio avahi-daemon[664]: Registering new address record for 169.254.139.214 on eth0.IPv4.
Jan 12 23:44:30 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:30 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:30 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:30 volumio go-librespot[3311]: time="2026-01-12T23:44:30-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]"
Jan 12 23:44:30 volumio go-librespot[3311]: time="2026-01-12T23:44:30-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]"
Jan 12 23:44:30 volumio go-librespot[3311]: time="2026-01-12T23:44:30-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]"
Jan 12 23:44:30 volumio go-librespot[3311]: time="2026-01-12T23:44:30-06:00" level=info msg="zeroconf server listening on port 45091"
Jan 12 23:44:30 volumio go-librespot[3311]: time="2026-01-12T23:44:30-06:00" level=debug msg="obtained new client token: AAAbEEDSkTgJtRlM4P4lE4QdCEQurM5TFcyLqjpiumZ221yxj1rFdMNZh21RHkL64WeHaTYYfk/egrfjBP3m7PmCCdDa0xnIwgG5G29ZaFk17Z+xB60U0THvFIsZewyjQjrIwRcSsgU3mYFNGqzILfPYYShNiaS4qCeBQp6iC+0CzgX00BJ8jlmRiYxWanluu9AZgmuFGLhYn/YthbG8ZpLEgxMUqt5+quk/Vet7ffS3VFWO9zX7kbzeiw=="
Jan 12 23:44:30 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.139.214
Jan 12 23:44:30 volumio go-librespot[3311]: time="2026-01-12T23:44:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:31 volumio go-librespot[3311]: time="2026-01-12T23:44:31-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:31 volumio go-librespot[3311]: time="2026-01-12T23:44:31-06:00" level=debug msg="completed challenge"
Jan 12 23:44:31 volumio volumio[3198]: info: Loading plugin "alarm-clock"...
Jan 12 23:44:31 volumio go-librespot[3311]: time="2026-01-12T23:44:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Jan 12 23:44:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:31 volumio volumio[3198]: info: Loading plugin "airplay_emulation"...
Jan 12 23:44:31 volumio volumio[3198]: info: Starting Shairport Sync
Jan 12 23:44:31 volumio volumio[3198]: info: Loading plugin "last_100"...
Jan 12 23:44:31 volumio volumio[3198]: info: Loading plugin "webradio"...
Jan 12 23:44:31 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.139.214
Jan 12 23:44:31 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.139.214
Jan 12 23:44:31 volumio avahi-daemon[664]: Withdrawing address record for 169.254.139.214 on eth0.
Jan 12 23:44:31 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:44:31 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:31 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:31 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:31 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:44:31 volumio volumio[3198]: info: Loading plugin "i2s_dacs"...
Jan 12 23:44:31 volumio volumio[3198]: info: I2S DAC not set, start Auto-detection
Jan 12 23:44:31 volumio volumio[3198]: info: Loading plugin "volumiodiscovery"...
Jan 12 23:44:31 volumio volumio[3198]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jan 12 23:44:31 volumio volumio[3198]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jan 12 23:44:31 volumio volumio[3198]: *** WARNING *** For more information see
Jan 12 23:44:31 volumio volumio[3198]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jan 12 23:44:31 volumio volumio[3198]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jan 12 23:44:31 volumio volumio[3198]: *** WARNING *** For more information see
Jan 12 23:44:31 volumio node[3198]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jan 12 23:44:31 volumio node[3198]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jan 12 23:44:31 volumio node[3198]: *** WARNING *** For more information see
Jan 12 23:44:31 volumio node[3198]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jan 12 23:44:31 volumio node[3198]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jan 12 23:44:31 volumio node[3198]: *** WARNING *** For more information see
Jan 12 23:44:31 volumio volumio[3198]: info: Applying required configuration parameters for plugin volumiodiscovery
Jan 12 23:44:31 volumio volumio[3198]: info: Discovery: Started advertising with name: Volumio
Jan 12 23:44:31 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jan 12 23:44:31 volumio volumio[3198]: info: Loading plugin "bandcamp"...
Jan 12 23:44:32 volumio volumio[3198]: info: Plugin calmradio is not enabled
Jan 12 23:44:32 volumio volumio[3198]: info: Loading plugin "soundcloud"...
Jan 12 23:44:33 volumio volumio[3198]: info: Loading plugin "spop"...
Jan 12 23:44:34 volumio volumio[3198]: info: Loading plugin "squeezelite_mc"...
Jan 12 23:44:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45.
Jan 12 23:44:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:34 volumio go-librespot[3352]: go-librespot daemon starting...
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-06:00" level=debug msg="app state loaded"
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-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]"
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-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]"
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-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]"
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-06:00" level=info msg="zeroconf server listening on port 46845"
Jan 12 23:44:34 volumio kernel: hwmon hwmon1: Voltage normalised
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-06:00" level=debug msg="obtained new client token: AADKsYsRvywXije/US3oXFgyk46Zeq1hPyCO67wx5P7GNUcb4APAb6HQakXk5UJOICO4n+pE1c6S/G1SB3cdc4wOafv00el6dhnYN2R+hHtoTY6GErgLuGpIL7/ckioLBKCqFWqKcdoxnqHi7LJo9IH8Jdy52xknlW9VDbrLb7zPUY8PTXlnfS8MMcW9V72p2YI/JYnRTbHfnCxRJLg7QBH4JFhSCrinzOW+7KLg5n5IWSDIwYva8zRdxQ=="
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-06:00" level=debug msg="completed challenge"
Jan 12 23:44:34 volumio volumio[3198]: info: Loading plugin "youtube2"...
Jan 12 23:44:34 volumio go-librespot[3353]: time="2026-01-12T23:44:34-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 "
Jan 12 23:44:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:35 volumio volumio[3198]: info: Loading plugin "ytcr"...
Jan 12 23:44:36 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.90.212
Jan 12 23:44:36 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:44:36 volumio avahi-daemon[664]: Registering new address record for 169.254.90.212 on eth0.IPv4.
Jan 12 23:44:36 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:36 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:36 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:36 volumio volumio[3198]: info: Loading plugin "ytmusic"...
Jan 12 23:44:37 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.90.212
Jan 12 23:44:37 volumio volumio[3198]: info: Plugin now_playing is not enabled
Jan 12 23:44:37 volumio volumio[3198]: info: Loading plugin "outputs"...
Jan 12 23:44:37 volumio volumio[3198]: info: Loading plugin "albumart"...
Jan 12 23:44:37 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.90.212
Jan 12 23:44:37 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.90.212
Jan 12 23:44:37 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:44:37 volumio avahi-daemon[664]: Withdrawing address record for 169.254.90.212 on eth0.
Jan 12 23:44:37 volumio volumio[3198]: info: Plugin example_plugin is not enabled
Jan 12 23:44:37 volumio volumio[3198]: info: Loading plugin "inputs"...
Jan 12 23:44:37 volumio volumio[3198]: info: Loading plugin "updater_comm"...
Jan 12 23:44:37 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:44:37 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:37 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:37 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:37 volumio volumio[3198]: info: Plugin mpdemulation is not enabled
Jan 12 23:44:37 volumio volumio[3198]: info: Loading plugin "rest_api"...
Jan 12 23:44:37 volumio volumio[3198]: info: Loading plugin "websocket"...
Jan 12 23:44:37 volumio volumio[3198]: info: Starting Socket.io Server version 1.7.4
Jan 12 23:44:37 volumio volumio[3198]: info: Plugin fusiondsp is not enabled
Jan 12 23:44:37 volumio volumio[3198]: info: Plugin mpdoutput is not enabled
Jan 12 23:44:37 volumio volumio[3198]: info: Plugin RoonBridge is not enabled
Jan 12 23:44:37 volumio volumio[3198]: info: Loading plugin "podcast"...
Jan 12 23:44:37 volumio volumio[3198]: info: ControllerPodcast::constructor
Jan 12 23:44:37 volumio volumio[3198]: info: Loading plugin "volusonic"...
Jan 12 23:44:37 volumio volumio[3377]: Forking 3 albumart workers
Jan 12 23:44:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46.
Jan 12 23:44:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:38 volumio go-librespot[3418]: go-librespot daemon starting...
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-06:00" level=debug msg="app state loaded"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-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]"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-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]"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-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]"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-06:00" level=info msg="zeroconf server listening on port 46863"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-06:00" level=debug msg="obtained new client token: AACwRolB27oUBZbklb3VI3joaRH+gTWwEhnuQnQVVhqCtSG6UpwpoQ0y9g4afyJtRjsAsr4NP7KHD0zj9xRF6TPG5Rm0ZBmTjih2X3FFppfW3zE54tBVpiCDxUytF+Ec9vqrsDwsurB9aICBk3PUoTeIMlYrw1aW73jiyxyHtk2nv6I4P0wRZqo7YFhuOlAgxpIGpYSM4Tyo4TT1yf6Aq0EuJLj3t0Z5lQO6/6qu5xEMX5qO11d3liQvLA=="
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-06:00" level=debug msg="completed challenge"
Jan 12 23:44:38 volumio go-librespot[3444]: time="2026-01-12T23:44:38-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 "
Jan 12 23:44:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:39 volumio volumio[3420]: Starting albumart workers
Jan 12 23:44:39 volumio volumio[3417]: Starting albumart workers
Jan 12 23:44:39 volumio volumio[3198]: info: Applying required configuration parameters for plugin volusonic
Jan 12 23:44:39 volumio volumio[3198]: info: Loading plugin "backup_restore"...
Jan 12 23:44:39 volumio volumio[3419]: Starting albumart workers
Jan 12 23:44:39 volumio volumio[3198]: info: Applying required configuration parameters for plugin backup_restore
Jan 12 23:44:39 volumio volumio[3198]: info: Plugin rpi_eeprom_config is not enabled
Jan 12 23:44:39 volumio volumio[3198]: info: Plugin rpi_eeprom_updater is not enabled
Jan 12 23:44:39 volumio volumio[3198]: info: Loading plugin "scheduledrestart"...
Jan 12 23:44:40 volumio volumio[3198]: info: Applying required configuration parameters for plugin scheduledrestart
Jan 12 23:44:40 volumio volumio[3198]: info: Plugin Bluetoothremote is not enabled
Jan 12 23:44:40 volumio volumio[3198]: info: Plugin music_services_shield is not enabled
Jan 12 23:44:40 volumio volumio[3198]: info: Loading plugin "Systeminfo"...
Jan 12 23:44:40 volumio volumio-remote-updater[14193]: [2026-01-12 23:44:40] [connect] Successful connection
Jan 12 23:44:40 volumio volumio[3198]: info: Plugin peppymeterbasic is not enabled
Jan 12 23:44:40 volumio volumio[3198]: info: Loading plugin "peppyspectrum"...
Jan 12 23:44:40 volumio volumio[3198]: info: Loading i18n strings for locale en
Jan 12 23:44:40 volumio volumio[3198]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Jan 12 23:44:40 volumio volumio[3198]: Updating browse sources language
Jan 12 23:44:40 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::initPlayerControls
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: Express server listening on port 3000
Jan 12 23:44:41 volumio volumio[3198]: [Metrics] WebUI: 16s 379.57ms
Jan 12 23:44:41 volumio volumio[3198]: info: CoreStateMachine::resetVolumioState
Jan 12 23:44:41 volumio volumio[3198]: info: CoreStateMachine::getcurrentVolume
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioRetrievevolume
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:41 volumio sudo[3481]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jan 12 23:44:41 volumio sudo[3481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:41 volumio sudo[3481]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:41 volumio sudo[3483]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 12 23:44:41 volumio sudo[3483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:41 volumio sudo[3483]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:41 volumio volumio[3198]: info: Volumio Network Manager: Network status updated: 1
Jan 12 23:44:41 volumio volumio[3198]: info: VolumeController:: Volume=100 Mute =false
Jan 12 23:44:41 volumio volumio[3198]: info: CoreStateMachine::pushState
Jan 12 23:44:41 volumio volumio[3198]: info: CorePlayQueue::getTrack 0
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioPushState
Jan 12 23:44:41 volumio volumio[3198]: info: CoreStateMachine::updateTrackBlock
Jan 12 23:44:41 volumio volumio[3198]: info: CorePlayQueue::getTrackBlock
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioRetrievevolume
Jan 12 23:44:41 volumio volumio-remote-updater[14193]: [2026-01-12 23:44:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768283080 101
Jan 12 23:44:41 volumio volumio[3198]: 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
Jan 12 23:44:41 volumio volumio[3198]: info: Reloading queue from file
Jan 12 23:44:41 volumio volumio[3198]: info: CoreStateMachine::setRepeat null single undefined
Jan 12 23:44:41 volumio volumio[3198]: info: CoreStateMachine::pushState
Jan 12 23:44:41 volumio volumio[3198]: info: CorePlayQueue::getTrack 0
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioPushState
Jan 12 23:44:41 volumio volumio[3198]: info: CoreStateMachine::setRandom null
Jan 12 23:44:41 volumio volumio[3198]: info: CoreStateMachine::pushState
Jan 12 23:44:41 volumio volumio[3198]: info: CorePlayQueue::getTrack 0
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioPushState
Jan 12 23:44:41 volumio volumio[3198]: info: Setting Device type: Raspberry PI
Jan 12 23:44:41 volumio volumio[3198]: info: VolumeController:: Volume=100 Mute =false
Jan 12 23:44:41 volumio volumio[3198]: info: CoreStateMachine::pushState
Jan 12 23:44:41 volumio volumio[3198]: info: CorePlayQueue::getTrack 0
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioPushState
Jan 12 23:44:41 volumio volumio[3198]: info: Completed loading Core Plugins
Jan 12 23:44:41 volumio volumio[3198]: info: Preparing to generate the ALSA configuration file
Jan 12 23:44:41 volumio sudo[3496]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Jan 12 23:44:41 volumio sudo[3496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:41 volumio volumio[3198]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Jan 12 23:44:41 volumio volumio[3198]: info: Discovery: Found device Volumio
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioGetState
Jan 12 23:44:41 volumio volumio[3198]: info: CorePlayQueue::getTrack 0
Jan 12 23:44:41 volumio volumio[3198]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954
Jan 12 23:44:41 volumio volumio[3198]: info: Discovery: Found device Volumio
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioGetState
Jan 12 23:44:41 volumio volumio[3198]: info: CorePlayQueue::getTrack 0
Jan 12 23:44:41 volumio volumio[3198]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Jan 12 23:44:41 volumio sudo[3496]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:41 volumio volumio[3198]: info: Reading ALSA contributions from plugins.
Jan 12 23:44:41 volumio volumio[3198]: info: Upmpdcli Daemon Started
Jan 12 23:44:41 volumio volumio[3198]: info: Asound.conf file unchanged, so no further update is needed
Jan 12 23:44:41 volumio volumio[3198]: info: Output device has changed, restarting MPD
Jan 12 23:44:41 volumio volumio[3198]: info: Output device has changed, restarting Shairport Sync
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:41 volumio sudo[3499]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jan 12 23:44:41 volumio sudo[3499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:41 volumio sudo[3499]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:41 volumio sudo[3501]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jan 12 23:44:41 volumio sudo[3501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:41 volumio volumio[3198]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jan 12 23:44:41 volumio volumio[3198]: info: ___________ START PLUGINS ___________
Jan 12 23:44:41 volumio volumio[3198]: info: ControllerMpd::onStart: Initializing MPD
Jan 12 23:44:41 volumio volumio[3198]: info: Creating MPD Configuration file
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:44:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Jan 12 23:44:41 volumio volumio[3198]: info: [1768283081675] CoreMusicLibrary::Adding element Media Servers
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:41 volumio sudo[3509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jan 12 23:44:41 volumio sudo[3509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:41 volumio sudo[3509]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:41 volumio sudo[3511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jan 12 23:44:41 volumio sudo[3511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jan 12 23:44:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47.
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:41 volumio volumio[3198]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:44:41 volumio volumio[3198]: info: [1768283081790] CoreMusicLibrary::Adding element Last_100
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:44:41 volumio volumio[3198]: info: [1768283081794] CoreMusicLibrary::Adding element Webradio
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jan 12 23:44:41 volumio volumio[3198]: info: Initializing BBC Radios
Jan 12 23:44:41 volumio go-librespot[3522]: go-librespot daemon starting...
Jan 12 23:44:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:41 volumio systemd[1]: mpd.service: Deactivated successfully.
Jan 12 23:44:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Jan 12 23:44:41 volumio systemd[1]: mpd.service: Consumed 4.335s CPU time.
Jan 12 23:44:41 volumio systemd[1]: mpd.socket: Deactivated successfully.
Jan 12 23:44:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Jan 12 23:44:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Jan 12 23:44:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Jan 12 23:44:41 volumio go-librespot[3531]: time="2026-01-12T23:44:41-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:41 volumio go-librespot[3531]: time="2026-01-12T23:44:41-06:00" level=debug msg="app state loaded"
Jan 12 23:44:41 volumio go-librespot[3531]: time="2026-01-12T23:44:41-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:41 volumio go-librespot[3531]: time="2026-01-12T23:44:41-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:44:41 volumio volumio[3198]: info: [1768283081903] CoreMusicLibrary::Adding element Bandcamp Discover
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:41 volumio volumio[3198]: Cannot find translation for source Bandcamp Discover
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:44:41 volumio volumio[3198]: info: [1768283081916] CoreMusicLibrary::Adding element SoundCloud
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:41 volumio volumio[3198]: Cannot find translation for source Bandcamp Discover
Jan 12 23:44:41 volumio volumio[3198]: Cannot find translation for source SoundCloud
Jan 12 23:44:41 volumio volumio[3198]: info: Creating Spotify config file
Jan 12 23:44:41 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio sudo[3543]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Jan 12 23:44:42 volumio sudo[3543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Jan 12 23:44:42 volumio sudo[3543]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:42 volumio go-librespot[3531]: time="2026-01-12T23:44:42-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]"
Jan 12 23:44:42 volumio go-librespot[3531]: time="2026-01-12T23:44:42-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]"
Jan 12 23:44:42 volumio go-librespot[3531]: time="2026-01-12T23:44:42-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]"
Jan 12 23:44:42 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.25.107
Jan 12 23:44:42 volumio avahi-daemon[664]: Registering new address record for 169.254.25.107 on eth0.IPv4.
Jan 12 23:44:42 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:44:42 volumio go-librespot[3531]: time="2026-01-12T23:44:42-06:00" level=info msg="zeroconf server listening on port 32819"
Jan 12 23:44:42 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:42 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:42 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:42 volumio go-librespot[3531]: time="2026-01-12T23:44:42-06:00" level=debug msg="obtained new client token: AACVXX6CL87bNf4+QIv29CTGx70c2GwFcKKi9UjwHPHJrgHPl08iR6iBumihIXzCztItAV6zQNXptubIEcXcuN4KSPf63OCsWzw/NVWOgHxjUfEoaxc4sVQ72FCPuaYQ8qTwH1bW7IlYsLaf7mPJHtkHhNnlWZRBk7un6+0XQGKHQqetFcvbj4BpBwI0hR6kL0X1aGik6l+sHX3s/CwzEK7zQKuRCAEpmc2+MH8MtC4EWdlUDfyaOpQ="
Jan 12 23:44:42 volumio volumio[3198]: info: [squeezelite_mc] Starting proxy server...
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:44:42 volumio volumio[3198]: info: [1768283082331] CoreMusicLibrary::Adding element YouTube2
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Bandcamp Discover
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source SoundCloud
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube2
Jan 12 23:44:42 volumio go-librespot[3531]: time="2026-01-12T23:44:42-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:44:42 volumio volumio[3198]: info: [1768283082351] CoreMusicLibrary::Adding element YouTube Music
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Bandcamp Discover
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source SoundCloud
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube2
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube Music
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:44:42 volumio volumio[3198]: info: [1768283082362] CoreMusicLibrary::Adding element Podcast
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Bandcamp Discover
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source SoundCloud
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube2
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube Music
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Podcast
Jan 12 23:44:42 volumio go-librespot[3531]: time="2026-01-12T23:44:42-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:42 volumio go-librespot[3531]: time="2026-01-12T23:44:42-06:00" level=debug msg="completed challenge"
Jan 12 23:44:42 volumio volumio[3198]: info: Loading i18n strings for locale en
Jan 12 23:44:42 volumio volumio[3198]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Jan 12 23:44:42 volumio volumio[3198]: Updating browse sources language
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Bandcamp Discover
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source SoundCloud
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube2
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube Music
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Podcast
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Bandcamp Discover
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source SoundCloud
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube2
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube Music
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Podcast
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:44:42 volumio volumio[3198]: info: [1768283082413] CoreMusicLibrary::Adding element Volusonic
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Bandcamp Discover
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source SoundCloud
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube2
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source YouTube Music
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Podcast
Jan 12 23:44:42 volumio volumio[3198]: Cannot find translation for source Volusonic
Jan 12 23:44:42 volumio go-librespot[3531]: time="2026-01-12T23:44:42-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 "
Jan 12 23:44:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:42 volumio volumio[3198]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Jan 12 23:44:42 volumio volumio[3198]: info: Volumio Calling Home
Jan 12 23:44:42 volumio volumio[3198]: info: [squeezelite_mc] Proxy server started on port 37575
Jan 12 23:44:42 volumio volumio[3198]: info: Preparing to generate the ALSA configuration file
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::volumioRetrievevolume
Jan 12 23:44:42 volumio volumio[3198]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Jan 12 23:44:42 volumio volumio[3198]: info: Reading ALSA contributions from plugins.
Jan 12 23:44:42 volumio volumio[3198]: info: MPD Permissions set
Jan 12 23:44:42 volumio volumio[3198]: info: MPD Permissions set
Jan 12 23:44:42 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.25.107
Jan 12 23:44:42 volumio volumio[3198]: info: Spotify config file written
Jan 12 23:44:42 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.25.107
Jan 12 23:44:42 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.25.107
Jan 12 23:44:42 volumio avahi-daemon[664]: Withdrawing address record for 169.254.25.107 on eth0.
Jan 12 23:44:42 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:44:42 volumio sudo[3570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Jan 12 23:44:42 volumio sudo[3570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:42 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:42 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:42 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:42 volumio volumio[3198]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Jan 12 23:44:42 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:44:42 volumio volumio[3198]: info: VolumeController:: Volume=100 Mute =false
Jan 12 23:44:42 volumio volumio[3198]: info: CoreStateMachine::pushState
Jan 12 23:44:42 volumio volumio[3198]: info: CorePlayQueue::getTrack 0
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::volumioPushState
Jan 12 23:44:42 volumio volumio[3198]: info: [squeezelite_mc] Server discovery started
Jan 12 23:44:42 volumio volumio[3198]: info: [squeezelite_mc] Player finder started
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:42 volumio go-librespot[3588]: go-librespot daemon starting...
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:42 volumio sudo[3570]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:42 volumio go-librespot[3596]: time="2026-01-12T23:44:42-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:42 volumio go-librespot[3596]: time="2026-01-12T23:44:42-06:00" level=debug msg="app state loaded"
Jan 12 23:44:42 volumio go-librespot[3596]: time="2026-01-12T23:44:42-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:43 volumio go-librespot[3596]: time="2026-01-12T23:44:43-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:43 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:43 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:43 volumio volumio[3198]: info: No need to fix Spotify hosts
Jan 12 23:44:43 volumio volumio[3198]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Jan 12 23:44:43 volumio volumio[3198]: info: Volumio called home
Jan 12 23:44:43 volumio go-librespot[3596]: time="2026-01-12T23:44: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]"
Jan 12 23:44:43 volumio go-librespot[3596]: time="2026-01-12T23:44: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]"
Jan 12 23:44:43 volumio go-librespot[3596]: time="2026-01-12T23:44: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]"
Jan 12 23:44:43 volumio go-librespot[3596]: time="2026-01-12T23:44:43-06:00" level=info msg="zeroconf server listening on port 41337"
Jan 12 23:44:43 volumio volumio[3198]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Jan 12 23:44:43 volumio volumio[3198]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Jan 12 23:44:43 volumio volumio[3198]: 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
Jan 12 23:44:43 volumio volumio[3198]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Jan 12 23:44:43 volumio volumio[3198]: SPOTIFY: BQAFz80sPevDliefLrP-2ZVYUS5xd1GHf0lnQ7-7nzD0AA_kNoTLUvdvKns_NXiZzzKD699sIc-gG8VvBEgN18LYXwDkCQt5Ar7GTtCIvN1e1cN1AwzqP4qChOIoBsXy5NZs_eg0RvWlMd6zme5QIVmBeL_KeGW6ir3biEhMpxNLtNO6vlIeZj59bpwtyY5EnATbsdTKNhNtqZgaCEAdpkw3-jlb2xwx-ByF0vI
Jan 12 23:44:43 volumio volumio[3198]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Jan 12 23:44:43 volumio volumio[3198]: info: New Spotify access token = BQAFz80sPevDliefLrP-2ZVYUS5xd1GHf0lnQ7-7nzD0AA_kNoTLUvdvKns_NXiZzzKD699sIc-gG8VvBEgN18LYXwDkCQt5Ar7GTtCIvN1e1cN1AwzqP4qChOIoBsXy5NZs_eg0RvWlMd6zme5QIVmBeL_KeGW6ir3biEhMpxNLtNO6vlIeZj59bpwtyY5EnATbsdTKNhNtqZgaCEAdpkw3-jlb2xwx-ByF0vI
Jan 12 23:44:43 volumio volumio[3198]: info: Spotify credentials grant success - running version from March 24, 2019
Jan 12 23:44:43 volumio go-librespot[3596]: time="2026-01-12T23:44:43-06:00" level=debug msg="obtained new client token: AAAMaRU4DOfY1AEfe+Os6AZls41OKKy1RL0XoCFLu+pQBMgctIn7T/iaZO9+EQ50vFDnWySsCUfZfBwFmY4lJhGM6GTQmEXX8B+kP8bv2z26mArQwwUcAnom94zopxV6rpyAtoc4lv8LabEPCPGdqBemv8l00BWPYkC6V9NXpcHYppVkFNuOtYnZB92jX24w1JlvV+2pcPpKa62EJiCTfnTqHWMXPXDVqPHmhaa8fJ89KgSLpJINXOPKzg=="
Jan 12 23:44:43 volumio volumio[3198]: info: Starting Shairport Sync
Jan 12 23:44:43 volumio volumio[3198]: info: Starting Shairport Sync
Jan 12 23:44:43 volumio sudo[3610]: 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
Jan 12 23:44:43 volumio sudo[3610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:43 volumio go-librespot[3596]: time="2026-01-12T23:44:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:43 volumio volumio[3198]: info: Starting Shairport Sync
Jan 12 23:44:43 volumio sudo[3610]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:43 volumio sudo[3612]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jan 12 23:44:43 volumio sudo[3612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:43 volumio go-librespot[3596]: time="2026-01-12T23:44:43-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:43 volumio go-librespot[3596]: time="2026-01-12T23:44:43-06:00" level=debug msg="completed challenge"
Jan 12 23:44:43 volumio sudo[3617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jan 12 23:44:43 volumio sudo[3617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:43 volumio sudo[3615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jan 12 23:44:43 volumio sudo[3615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:43 volumio volumio[3198]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Jan 12 23:44:43 volumio go-librespot[3596]: time="2026-01-12T23:44: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 "
Jan 12 23:44:43 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Jan 12 23:44:43 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Jan 12 23:44:43 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:44:43 volumio systemd[1]: shairport-sync.service: Consumed 1.952s CPU time.
Jan 12 23:44:43 volumio volumio[3198]: info: Asound.conf file unchanged, so no further update is needed
Jan 12 23:44:43 volumio volumio[3198]: info: Output device has changed, restarting MPD
Jan 12 23:44:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:43 volumio sudo[3623]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Jan 12 23:44:43 volumio sudo[3623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:43 volumio sudo[3623]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:43 volumio volumio[3198]: info: Output device has changed, restarting Shairport Sync
Jan 12 23:44:43 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:43 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:43 volumio sudo[3626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jan 12 23:44:43 volumio sudo[3626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:43 volumio sudo[3626]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:43 volumio sudo[3629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jan 12 23:44:43 volumio sudo[3629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:43 volumio volumio[3198]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jan 12 23:44:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:44:43 volumio sudo[3612]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:43 volumio sudo[3617]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:43 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Jan 12 23:44:43 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Jan 12 23:44:43 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:44:43 volumio volumio[3198]: info: MPD Permissions set
Jan 12 23:44:43 volumio volumio[3198]: info: Shairport-Sync Started
Jan 12 23:44:43 volumio volumio[3198]: Error adding Membership: Error: addMembership EINVAL
Jan 12 23:44:43 volumio volumio[3198]: info: Shairport-Sync Started
Jan 12 23:44:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:44:43 volumio volumio[3198]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Jan 12 23:44:43 volumio systemd[1]: mpd.service: Deactivated successfully.
Jan 12 23:44:43 volumio sudo[3615]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Jan 12 23:44:43 volumio systemd[1]: mpd.service: Consumed 1.817s CPU time.
Jan 12 23:44:43 volumio systemd[1]: mpd.socket: Deactivated successfully.
Jan 12 23:44:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Jan 12 23:44:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Jan 12 23:44:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Jan 12 23:44:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Jan 12 23:44:43 volumio volumio[3198]: info: Shairport-Sync Started
Jan 12 23:44:43 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:43 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:43 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:43 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:44 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:44 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:44 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:44 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:44 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:44:44 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:44 volumio volumio[3198]: info: CoreCommandRouter::volumioGetState
Jan 12 23:44:44 volumio volumio[3198]: info: CorePlayQueue::getTrack 0
Jan 12 23:44:44 volumio sudo[3643]: 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
Jan 12 23:44:44 volumio sudo[3643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:44 volumio sudo[3643]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:44 volumio volumio[3198]: info: Starting Shairport Sync
Jan 12 23:44:44 volumio volumio[3198]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true
Jan 12 23:44:44 volumio sudo[3668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jan 12 23:44:44 volumio sudo[3668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:44 volumio sudo[3645]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Jan 12 23:44:44 volumio sudo[3645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Jan 12 23:44:44 volumio sudo[3671]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Jan 12 23:44:44 volumio sudo[3671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:44 volumio sudo[3645]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:44 volumio volumio[3198]: 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"}
Jan 12 23:44:44 volumio volumio[3198]: info: Spotify Successfully logged in
Jan 12 23:44:44 volumio volumio[3198]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:44:44 volumio volumio[3198]: info: [1768283084277] CoreMusicLibrary::Adding element Spotify
Jan 12 23:44:44 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:44:44 volumio volumio[3198]: Cannot find translation for source Bandcamp Discover
Jan 12 23:44:44 volumio volumio[3198]: Cannot find translation for source SoundCloud
Jan 12 23:44:44 volumio volumio[3198]: Cannot find translation for source YouTube2
Jan 12 23:44:44 volumio volumio[3198]: Cannot find translation for source YouTube Music
Jan 12 23:44:44 volumio volumio[3198]: Cannot find translation for source Podcast
Jan 12 23:44:44 volumio volumio[3198]: Cannot find translation for source Volusonic
Jan 12 23:44:44 volumio volumio[3198]: Cannot find translation for source Spotify
Jan 12 23:44:44 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Jan 12 23:44:44 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Jan 12 23:44:44 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:44:44 volumio systemd[1]: Reloading.
Jan 12 23:44:44 volumio kernel: hwmon hwmon1: Undervoltage detected!
Jan 12 23:44:45 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:45 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:45 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:44:45 volumio volumio[3198]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 12 23:44:46 volumio volumio[3198]: info: go-librespot daemon successfully initialized
Jan 12 23:44:46 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.
Jan 12 23:44:46 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.
Jan 12 23:44:47 volumio sudo[3671]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48.
Jan 12 23:44:47 volumio volumio[3198]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Jan 12 23:44:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:47 volumio sudo[3703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Jan 12 23:44:47 volumio sudo[3703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:47 volumio go-librespot[3709]: go-librespot daemon starting...
Jan 12 23:44:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:44:47 volumio sudo[3668]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:47 volumio volumio[3198]: info: Shairport-Sync Started
Jan 12 23:44:47 volumio go-librespot[3712]: time="2026-01-12T23:44:47-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:47 volumio go-librespot[3712]: time="2026-01-12T23:44:47-06:00" level=debug msg="app state loaded"
Jan 12 23:44:47 volumio go-librespot[3712]: time="2026-01-12T23:44:47-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:47 volumio go-librespot[3712]: time="2026-01-12T23:44:47-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:47 volumio sudo[3703]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:47 volumio volumio[3198]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true
Jan 12 23:44:47 volumio sudo[3734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite
Jan 12 23:44:47 volumio sudo[3734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:47 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Jan 12 23:44:48 volumio go-librespot[3712]: time="2026-01-12T23:44: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-gew4.spotify.com:80]"
Jan 12 23:44:48 volumio go-librespot[3712]: time="2026-01-12T23:44:48-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]"
Jan 12 23:44:48 volumio go-librespot[3712]: time="2026-01-12T23:44:48-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]"
Jan 12 23:44:48 volumio go-librespot[3712]: time="2026-01-12T23:44:48-06:00" level=info msg="zeroconf server listening on port 39521"
Jan 12 23:44:48 volumio systemd[1]: squeezelite.service: Deactivated successfully.
Jan 12 23:44:48 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jan 12 23:44:48 volumio sudo[3734]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:48 volumio go-librespot[3712]: time="2026-01-12T23:44:48-06:00" level=debug msg="obtained new client token: AABcjiHrZytof+6mDp+PUv7G8BUHEB/NVTBWxZiJO79HIhbSZKNsKb74RUiY/g5wROFUbaEb/gNEuUa3wKDJTfq6Uc0H5WNuFnuTioA+tA93GHl9Tb2a336eY1Z9RgFkVFSDsyn/tCTt0Z7MCNiD6MS5Y5DThBHjwjejslPKSTkfL6ehO4CUg6w3YvB3qlX5hXJpzOR5ASUbF4gmxK4KrweaB/RhvGvNuFK5tbdXcJqobY7DuA7KDbM="
Jan 12 23:44:48 volumio go-librespot[3712]: time="2026-01-12T23:44:48-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:48 volumio go-librespot[3712]: time="2026-01-12T23:44:48-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:48 volumio go-librespot[3712]: time="2026-01-12T23:44:48-06:00" level=debug msg="completed challenge"
Jan 12 23:44:48 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.29.155
Jan 12 23:44:48 volumio avahi-daemon[664]: Registering new address record for 169.254.29.155 on eth0.IPv4.
Jan 12 23:44:48 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:44:48 volumio go-librespot[3712]: time="2026-01-12T23:44: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 "
Jan 12 23:44:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:48 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:48 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:48 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:48 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.29.155
Jan 12 23:44:48 volumio volumio[3198]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Jan 12 23:44:48 volumio sudo[3754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Jan 12 23:44:48 volumio sudo[3754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:48 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.29.155
Jan 12 23:44:48 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.29.155
Jan 12 23:44:48 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:44:48 volumio avahi-daemon[664]: Withdrawing address record for 169.254.29.155 on eth0.
Jan 12 23:44:48 volumio sudo[3754]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:48 volumio volumio[3198]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log
Jan 12 23:44:48 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:44:48 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:48 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:48 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:48 volumio sudo[3768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log
Jan 12 23:44:48 volumio sudo[3768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:48 volumio sudo[3768]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:48 volumio volumio[3198]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Jan 12 23:44:48 volumio sudo[3777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Jan 12 23:44:48 volumio sudo[3777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:49 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator...
Jan 12 23:44:49 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator.
Jan 12 23:44:49 volumio sudo[3777]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:49 volumio mpd[3674]: 2026-01-12T23:44:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Jan 12 23:44:49 volumio volumio[3198]: info: Initializing connection to go-librespot Websocket
Jan 12 23:44:49 volumio volumio[3198]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jan 12 23:44:49 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Jan 12 23:44:49 volumio sudo[3629]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:49 volumio sudo[3511]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:49 volumio sudo[3501]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:49 volumio volumio[3198]: error: MPD error: The expression evaluated to a falsy value:
Jan 12 23:44:49 volumio volumio[3198]: assert.ok(self.idling)
Jan 12 23:44:49 volumio volumio[3198]: error: The expression evaluated to a falsy value:
Jan 12 23:44:49 volumio volumio[3198]: assert.ok(self.idling)
Jan 12 23:44:49 volumio volumio[3198]: error: MPD error: The expression evaluated to a falsy value:
Jan 12 23:44:49 volumio volumio[3198]: assert.ok(self.idling)
Jan 12 23:44:49 volumio volumio[3198]: error: The expression evaluated to a falsy value:
Jan 12 23:44:49 volumio volumio[3198]: assert.ok(self.idling)
Jan 12 23:44:49 volumio volumio[3198]: error: updateQueue error: null
Jan 12 23:44:49 volumio volumio[3198]: info: MPD running with PID3674
Jan 12 23:44:49 volumio volumio[3198]: ,establishing connection
Jan 12 23:44:49 volumio volumio[3198]: error: updateQueue error: null
Jan 12 23:44:49 volumio volumio[3198]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Jan 12 23:44:49 volumio sudo[3788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Jan 12 23:44:49 volumio sudo[3788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:49 volumio sudo[3788]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:50 volumio volumio[3198]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Jan 12 23:44:50 volumio sudo[3791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Jan 12 23:44:50 volumio sudo[3791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:50 volumio sudo[3791]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:50 volumio volumio[3198]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Jan 12 23:44:50 volumio sudo[3794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Jan 12 23:44:50 volumio sudo[3794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:50 volumio sudo[3794]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:51 volumio kernel: hwmon hwmon1: Voltage normalised
Jan 12 23:44:51 volumio volumio[3198]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Jan 12 23:44:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49.
Jan 12 23:44:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:51 volumio sudo[3798]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Jan 12 23:44:51 volumio sudo[3798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:51 volumio go-librespot[3799]: go-librespot daemon starting...
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44:51-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44:51-06:00" level=debug msg="app state loaded"
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44:51-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44:51-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:51 volumio sudo[3798]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44: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]"
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44: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]"
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44: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]"
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44:51-06:00" level=info msg="zeroconf server listening on port 38831"
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44:51-06:00" level=debug msg="obtained new client token: AACJPHxqdTe/Ekpf7TA3HIYTZaLNoBOQyNyKoiFyJTtZpl71GeclY6X45zSdGAoz1u1/loJ5pzEsZ+8xVAedQhtZlNUYChS995Foia7vabRHR1KechjJmxTOdEMAX9Y9DqlMGir7J3C3p1xSO4vyznKwrWgryHXv9BN6PnBLXXFqHpaUORm2msYHVuCD4tR4IHR2CB/F7IxENcp5oYBPy+OTbn0J7N1H/NX1E9lFICivviFQnYIERYmR4w=="
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44:51-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44:51-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:51 volumio go-librespot[3801]: time="2026-01-12T23:44:51-06:00" level=debug msg="completed challenge"
Jan 12 23:44:52 volumio go-librespot[3801]: time="2026-01-12T23:44: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 "
Jan 12 23:44:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:52 volumio volumio[3198]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Jan 12 23:44:52 volumio sudo[3809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Jan 12 23:44:52 volumio sudo[3809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:52 volumio sudo[3809]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:52 volumio volumio[3198]: info: Completed starting Core Plugins
Jan 12 23:44:52 volumio volumio[3198]: info: -------------------------------------------
Jan 12 23:44:52 volumio volumio[3198]: info: ----- MyVolumio plugins startup ----
Jan 12 23:44:52 volumio volumio[3198]: info: -------------------------------------------
Jan 12 23:44:52 volumio volumio[3198]: info: [MyVolumio PluginManager] Fetching plans data....
Jan 12 23:44:52 volumio volumio[3198]: info: Initializing connection to go-librespot Websocket
Jan 12 23:44:52 volumio volumio[3198]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jan 12 23:44:52 volumio sudo[3812]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Jan 12 23:44:52 volumio sudo[3812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:52 volumio sudo[3814]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Jan 12 23:44:52 volumio sudo[3814]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:52 volumio sudo[3816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Jan 12 23:44:52 volumio sudo[3816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:44:52 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Jan 12 23:44:52 volumio systemd[1]: mpd_monitor.service: Deactivated successfully.
Jan 12 23:44:52 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Jan 12 23:44:52 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Jan 12 23:44:52 volumio sudo[3816]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:52 volumio sudo[3812]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:52 volumio sudo[3814]: pam_unix(sudo:session): session closed for user root
Jan 12 23:44:52 volumio mpd_monitor.sh[3820]: MPD Monitor Service: Starting MPD Monitor Service
Jan 12 23:44:52 volumio volumio[3198]: info: Successfully started MPD Monitor
Jan 12 23:44:52 volumio volumio[3198]: info: Successfully started MPD Monitor
Jan 12 23:44:52 volumio volumio[3198]: info: Successfully started MPD Monitor
Jan 12 23:44:54 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.85.194
Jan 12 23:44:54 volumio avahi-daemon[664]: Registering new address record for 169.254.85.194 on eth0.IPv4.
Jan 12 23:44:54 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:44:54 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:54 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:54 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:54 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.85.194
Jan 12 23:44:54 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.85.194
Jan 12 23:44:54 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.85.194
Jan 12 23:44:54 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:44:54 volumio avahi-daemon[664]: Withdrawing address record for 169.254.85.194 on eth0.
Jan 12 23:44:55 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:55 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:44:55 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:44:55 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:44:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50.
Jan 12 23:44:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:55 volumio go-librespot[3856]: go-librespot daemon starting...
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-06:00" level=debug msg="app state loaded"
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:55 volumio volumio[3198]: info: Initializing connection to go-librespot Websocket
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-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]"
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-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]"
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-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]"
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-06:00" level=info msg="zeroconf server listening on port 45109"
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-06:00" level=debug msg="obtained new client token: AACBYDO2QTLmec99hPRrFRvJ7b6U7ROjeuu0YX9Oiw0XISA4rLkbJP4tMXrF5Z09OimGDE4Kz0ge9y+u1xOVcoZVIgOAoiXh67Q3OAuVrrFyxMasUIuEAqXYsqa8c41NmgV1sRdWwUmvBZDanLn3cFJEQYEpyct5XxdC8WsHS5VdsJ1hD/psxp/Fcr/pf4ValVePN8b9LXwPH6Rf7/fJdCqzNehFsaqTLwpwLYRdFQChFpjgX1IgtCvszQ=="
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-06:00" level=debug msg="new websocket client"
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:55 volumio go-librespot[3857]: time="2026-01-12T23:44:55-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:56 volumio go-librespot[3857]: time="2026-01-12T23:44:56-06:00" level=debug msg="completed challenge"
Jan 12 23:44:56 volumio go-librespot[3857]: time="2026-01-12T23:44: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 "
Jan 12 23:44:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:56 volumio volumio[3198]: info: Connection to go-librespot Websocket established
Jan 12 23:44:57 volumio kernel: hwmon hwmon1: Undervoltage detected!
Jan 12 23:44:58 volumio volumio[3198]: info: Connection to go-librespot Websocket closed
Jan 12 23:44:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51.
Jan 12 23:44:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:44:59 volumio go-librespot[3879]: go-librespot daemon starting...
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44:59-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44:59-06:00" level=debug msg="app state loaded"
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44:59-06:00" level=debug msg="stored credentials not found"
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44:59-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:44:59 volumio volumio[3198]: info: Getting Spotify volume
Jan 12 23:44:59 volumio volumio[3198]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44: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]"
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44: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]"
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44: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]"
Jan 12 23:44:59 volumio volumio[3198]: info: CoreCommandRouter::volumioGetState
Jan 12 23:44:59 volumio volumio[3198]: info: CorePlayQueue::getTrack 0
Jan 12 23:44:59 volumio volumio[3198]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44:59-06:00" level=info msg="zeroconf server listening on port 35219"
Jan 12 23:44:59 volumio volumio[3198]: SPOTIFY: SPOTIFY VOLUME undefined
Jan 12 23:44:59 volumio volumio[3198]: SPOTIFY: VOLUMIO VOLUME 100
Jan 12 23:44:59 volumio volumio[3198]: info: Aligning Spotify Volume to Volumio Volume
Jan 12 23:44:59 volumio volumio[3198]: info: CoreCommandRouter::volumioGetState
Jan 12 23:44:59 volumio volumio[3198]: info: CorePlayQueue::getTrack 0
Jan 12 23:44:59 volumio volumio[3198]: info: Setting Spotify Volume from Volumio: 100
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44:59-06:00" level=debug msg="obtained new client token: AACwVuZTda4PCxHxtMC0qRH62tGaUoTgq6FmfBIEYnJlhA3iInbZqe4prbcAJgmigqiQvSkAusWPVr4qnmYuxwOwWDM20WLRESNU31N403cJ214gm7JLFJBtiIf8o5tQrKXQdbN5/doPMaenBNCSymURgsxr2inSn//1pju2ivvaz4nhvB0ObV5EqsfFkFPCXb2v1AJcKiHpJjlZT/OrxXLAxsrf6CYW50ujOzlIGhipPwWHq2dboCurFg=="
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44:59-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44:59-06:00" level=debug msg="completed keyexchange"
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44:59-06:00" level=debug msg="completed challenge"
Jan 12 23:44:59 volumio go-librespot[3880]: time="2026-01-12T23:44:59-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 "
Jan 12 23:44:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:44:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:44:59 volumio volumio[3198]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jan 12 23:44:59 volumio volumio[3198]: Error: socket hang up
Jan 12 23:44:59 volumio volumio[3198]: at connResetException (node:internal/errors:720:14)
Jan 12 23:44:59 volumio volumio[3198]: at Socket.socketOnEnd (node:_http_client:519:23)
Jan 12 23:44:59 volumio volumio[3198]: at Socket.emit (node:events:526:35)
Jan 12 23:44:59 volumio volumio[3198]: at endReadableNT (node:internal/streams/readable:1376:12)
Jan 12 23:44:59 volumio volumio[3198]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Jan 12 23:44:59 volumio volumio[3198]: code: 'ECONNRESET',
Jan 12 23:44:59 volumio volumio[3198]: response: undefined
Jan 12 23:44:59 volumio volumio[3198]: }
Jan 12 23:44:59 volumio volumio[3198]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jan 12 23:45:00 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.244.46
Jan 12 23:45:00 volumio avahi-daemon[664]: Registering new address record for 169.254.244.46 on eth0.IPv4.
Jan 12 23:45:00 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:45:00 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:00 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:00 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.244.46
Jan 12 23:45:00 volumio sudo[3917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-12 23:44'
Jan 12 23:45:00 volumio sudo[3917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:00 volumio sudo[3917]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:01 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.244.46
Jan 12 23:45:01 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.244.46
Jan 12 23:45:01 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:45:01 volumio avahi-daemon[664]: Withdrawing address record for 169.254.244.46 on eth0.
Jan 12 23:45:01 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:45:01 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:01 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:01 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:01 volumio kernel: hwmon hwmon1: Voltage normalised
Jan 12 23:45:01 volumio volumio-remote-updater[14193]: [2026-01-12 23:45:01] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Jan 12 23:45:01 volumio volumio-remote-updater[14193]: [2026-01-12 23:45:01] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Jan 12 23:45:01 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:45:01 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Jan 12 23:45:01 volumio systemd[1]: volumio.service: Consumed 46.259s CPU time.
Jan 12 23:45:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Jan 12 23:45:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Jan 12 23:45:01 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22157.
Jan 12 23:45:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Jan 12 23:45:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Jan 12 23:45:02 volumio systemd[1]: volumio.service: Consumed 46.259s CPU time.
Jan 12 23:45:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Jan 12 23:45:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Jan 12 23:45:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52.
Jan 12 23:45:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:03 volumio go-librespot[3967]: go-librespot daemon starting...
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45:03-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45:03-06:00" level=debug msg="app state loaded"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45:03-06:00" level=debug msg="stored credentials not found"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45:03-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45: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]"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45: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]"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45: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]"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45:03-06:00" level=info msg="zeroconf server listening on port 34335"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45:03-06:00" level=debug msg="obtained new client token: AADZ/zNdINVEwxec6dmDWh03vxNrptPVn+mF519pOm19CmogtgdV6npJzuxvHC4HzVG0A5UEvY065ChMKsmc50tymFTEM2QhVKZJrN+wlUCRG8pOIIKKRWPwWjvMIdym8k7CBTu1CdnbIyv3j8uUi0qeiN0/g31WZDh3nRUeGZdGdUtc/8a8CFNcl1wAdq2jJZ2ZtQGmQfA4kitbt2EUll44ZWvXCY6WUm373UkM8S6oxQhKIgP+GMkVvw=="
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45:03-06:00" level=debug msg="completed keyexchange"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45:03-06:00" level=debug msg="completed challenge"
Jan 12 23:45:03 volumio go-librespot[3968]: time="2026-01-12T23:45: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 "
Jan 12 23:45:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:45:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:45:04 volumio volumio[3952]: info: -------------------------------------------
Jan 12 23:45:04 volumio volumio[3952]: info: ----- Volumio3 ----
Jan 12 23:45:04 volumio volumio[3952]: info: -------------------------------------------
Jan 12 23:45:04 volumio volumio[3952]: info: ----- System startup ----
Jan 12 23:45:04 volumio volumio[3952]: info: -------------------------------------------
Jan 12 23:45:04 volumio volumio[3952]: info: MYVOLUMIO Environment detected
Jan 12 23:45:04 volumio volumio[3952]: info: Plugin folders cleanup
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning into folder /volumio/app/plugins/
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category audio_interface
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category miscellanea
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category music_service
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category plugins.json
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category system_controller
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category user_interface
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning into folder /data/plugins/
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category audio_interface
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category music_service
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category system_controller
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category system_hardware
Jan 12 23:45:04 volumio volumio[3952]: info: Scanning category user_interface
Jan 12 23:45:04 volumio volumio[3952]: info: Plugin folders cleanup completed
Jan 12 23:45:04 volumio volumio[3952]: info: -------------------------------------------
Jan 12 23:45:04 volumio volumio[3952]: info: ----- Core plugins startup ----
Jan 12 23:45:04 volumio volumio[3952]: info: -------------------------------------------
Jan 12 23:45:04 volumio volumio[3952]: info: Loading plugins from folder /volumio/app/plugins/
Jan 12 23:45:04 volumio volumio[3952]: info: Adding plugin upnp to MyMusic Plugins
Jan 12 23:45:04 volumio volumio[3952]: info: Adding plugin airplay_emulation to MyMusic Plugins
Jan 12 23:45:04 volumio volumio[3952]: info: Adding plugin upnp_browser to MyMusic Plugins
Jan 12 23:45:04 volumio volumio[3952]: info: Loading plugins from folder /data/plugins/
Jan 12 23:45:04 volumio volumio[3952]: info: Loading plugin "system"...
Jan 12 23:45:04 volumio volumio[3952]: info: Loading plugin "appearance"...
Jan 12 23:45:05 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.184.5
Jan 12 23:45:05 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:45:05 volumio avahi-daemon[664]: Registering new address record for 169.254.184.5 on eth0.IPv4.
Jan 12 23:45:05 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:05 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:05 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:05 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.184.5
Jan 12 23:45:06 volumio volumio[3952]: info: Loading plugin "network"...
Jan 12 23:45:06 volumio volumio[3952]: info: Refreshing Cached IP Addresses
Jan 12 23:45:06 volumio sudo[4005]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jan 12 23:45:06 volumio sudo[4007]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 12 23:45:06 volumio sudo[4005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:06 volumio sudo[4007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:06 volumio volumio[3952]: info: Loading plugin "services"...
Jan 12 23:45:06 volumio sudo[4007]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:06 volumio volumio[3952]: info: Loading plugin "alsa_controller"...
Jan 12 23:45:06 volumio sudo[4005]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:06 volumio sudo[4015]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Jan 12 23:45:06 volumio sudo[4015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:06 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jan 12 23:45:06 volumio volumio[3952]: info: Loading plugin "wizard"...
Jan 12 23:45:06 volumio volumio[3952]: info: Loading plugin "networkfs"...
Jan 12 23:45:06 volumio volumio[3952]: info: Starting Udev Watcher for removable devices
Jan 12 23:45:06 volumio volumio[3952]: info: Ignoring mount for partition: boot
Jan 12 23:45:06 volumio volumio[3952]: info: Ignoring mount for partition: volumio
Jan 12 23:45:06 volumio volumio[3952]: info: Ignoring mount for partition: volumio_data
Jan 12 23:45:06 volumio volumio[3952]: info: Mounting Device Wikipedia
Jan 12 23:45:06 volumio sudo[4044]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime
Jan 12 23:45:06 volumio sudo[4044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:06 volumio sudo[4044]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:06 volumio volumio[3952]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Jan 12 23:45:06 volumio volumio[3952]: dmesg(1) may have more information after failed mount system call.
Jan 12 23:45:06 volumio volumio[3952]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime
Jan 12 23:45:06 volumio volumio[3952]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia.
Jan 12 23:45:06 volumio volumio[3952]: dmesg(1) may have more information after failed mount system call.
Jan 12 23:45:06 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jan 12 23:45:06 volumio volumio[3952]: info: Loading plugin "volumio_command_line_client"...
Jan 12 23:45:06 volumio volumio[3952]: info: Loading plugin "upnp"...
Jan 12 23:45:06 volumio volumio[3952]: info: [1768283106466] Starting Upmpd Daemon
Jan 12 23:45:06 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jan 12 23:45:06 volumio volumio[3952]: info: Loading plugin "my_music"...
Jan 12 23:45:06 volumio volumio[3952]: info: Loading plugin "mpd"...
Jan 12 23:45:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.184.5
Jan 12 23:45:06 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.184.5
Jan 12 23:45:06 volumio avahi-daemon[664]: Withdrawing address record for 169.254.184.5 on eth0.
Jan 12 23:45:06 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:45:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53.
Jan 12 23:45:06 volumio volumio-remote-updater[14193]: [2026-01-12 23:45:06] [connect] Successful connection
Jan 12 23:45:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:06 volumio go-librespot[4051]: go-librespot daemon starting...
Jan 12 23:45:06 volumio sudo[4015]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:06 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:45:06 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:06 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:06 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:06 volumio go-librespot[4060]: time="2026-01-12T23:45:06-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:45:06 volumio go-librespot[4060]: time="2026-01-12T23:45:06-06:00" level=debug msg="app state loaded"
Jan 12 23:45:06 volumio go-librespot[4060]: time="2026-01-12T23:45:06-06:00" level=debug msg="stored credentials not found"
Jan 12 23:45:06 volumio go-librespot[4060]: time="2026-01-12T23:45:06-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:45:07 volumio volumio[3952]: info: Loading plugin "upnp_browser"...
Jan 12 23:45:07 volumio go-librespot[4060]: time="2026-01-12T23:45: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Jan 12 23:45:07 volumio go-librespot[4060]: time="2026-01-12T23:45:07-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]"
Jan 12 23:45:07 volumio go-librespot[4060]: time="2026-01-12T23:45:07-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]"
Jan 12 23:45:07 volumio go-librespot[4060]: time="2026-01-12T23:45:07-06:00" level=info msg="zeroconf server listening on port 46755"
Jan 12 23:45:07 volumio go-librespot[4060]: time="2026-01-12T23:45:07-06:00" level=debug msg="obtained new client token: AAC6X1+/c2kwnvCqRfqKE2cFg2zKyH5/RMPFaZWiygjKey/KKSzyMzLGyXDdPbA09vc6Rlsguh0xYqRI4aK28F+y4Nir6kkjdnzaB1cgSQ6qZKBGKaCkDlZi1ruQ2VNqBYvEgGPy1X/WIFObFq5qQ21uCvKg1i13k0RYkBmKOB/gLUAEYDh/Lh/TmxwlEctNc/Y+R6GVU+NFZ+BoUcduxvbmUcKP5mXvSPo0yVvs+dwCjoqBVHns8J0f2g=="
Jan 12 23:45:07 volumio go-librespot[4060]: time="2026-01-12T23:45:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:45:07 volumio go-librespot[4060]: time="2026-01-12T23:45:07-06:00" level=debug msg="completed keyexchange"
Jan 12 23:45:07 volumio go-librespot[4060]: time="2026-01-12T23:45:07-06:00" level=debug msg="completed challenge"
Jan 12 23:45:07 volumio go-librespot[4060]: time="2026-01-12T23:45: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 "
Jan 12 23:45:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:45:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:45:07 volumio kernel: hwmon hwmon1: Undervoltage detected!
Jan 12 23:45:09 volumio volumio[3952]: info: Loading plugin "alarm-clock"...
Jan 12 23:45:09 volumio volumio[3952]: info: Loading plugin "airplay_emulation"...
Jan 12 23:45:10 volumio volumio[3952]: info: Starting Shairport Sync
Jan 12 23:45:10 volumio volumio[3952]: info: Loading plugin "last_100"...
Jan 12 23:45:10 volumio volumio[3952]: info: Loading plugin "webradio"...
Jan 12 23:45:10 volumio volumio[3952]: info: Loading plugin "i2s_dacs"...
Jan 12 23:45:10 volumio volumio[3952]: info: I2S DAC not set, start Auto-detection
Jan 12 23:45:10 volumio volumio[3952]: info: Loading plugin "volumiodiscovery"...
Jan 12 23:45:10 volumio volumio[3952]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jan 12 23:45:10 volumio volumio[3952]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jan 12 23:45:10 volumio volumio[3952]: *** WARNING *** For more information see
Jan 12 23:45:10 volumio volumio[3952]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jan 12 23:45:10 volumio volumio[3952]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jan 12 23:45:10 volumio volumio[3952]: *** WARNING *** For more information see
Jan 12 23:45:10 volumio node[3952]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jan 12 23:45:10 volumio node[3952]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jan 12 23:45:10 volumio node[3952]: *** WARNING *** For more information see
Jan 12 23:45:10 volumio node[3952]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jan 12 23:45:10 volumio node[3952]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jan 12 23:45:10 volumio node[3952]: *** WARNING *** For more information see
Jan 12 23:45:10 volumio volumio[3952]: info: Applying required configuration parameters for plugin volumiodiscovery
Jan 12 23:45:10 volumio volumio[3952]: info: Discovery: Started advertising with name: Volumio
Jan 12 23:45:10 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jan 12 23:45:10 volumio volumio[3952]: info: Loading plugin "bandcamp"...
Jan 12 23:45:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54.
Jan 12 23:45:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:10 volumio go-librespot[4074]: go-librespot daemon starting...
Jan 12 23:45:10 volumio go-librespot[4075]: time="2026-01-12T23:45:10-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:45:10 volumio go-librespot[4075]: time="2026-01-12T23:45:10-06:00" level=debug msg="app state loaded"
Jan 12 23:45:10 volumio go-librespot[4075]: time="2026-01-12T23:45:10-06:00" level=debug msg="stored credentials not found"
Jan 12 23:45:10 volumio go-librespot[4075]: time="2026-01-12T23:45:10-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:45:11 volumio go-librespot[4075]: time="2026-01-12T23:45: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Jan 12 23:45:11 volumio go-librespot[4075]: time="2026-01-12T23:45:11-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]"
Jan 12 23:45:11 volumio go-librespot[4075]: time="2026-01-12T23:45:11-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]"
Jan 12 23:45:11 volumio go-librespot[4075]: time="2026-01-12T23:45:11-06:00" level=info msg="zeroconf server listening on port 34233"
Jan 12 23:45:11 volumio go-librespot[4075]: time="2026-01-12T23:45:11-06:00" level=debug msg="obtained new client token: AAC6/ZepSrLVHZUcXgRJN9+iQ8ttN0LHVahy5W7Dq+YgJC7yHcw896hHaYUybrofhJFDncUrqmqPe6NGXCrasiMAwQ0BBP+PmxuJQHSZgY8HaDzgm8n4IE38L1dHvhUhiq+yKPZrRjE2KAFOe0ctsTAha7roswaKUbhatm2OuldpVZm0Y4daMMCc6GHs/OQ8CtZRBLnpvM6YTCd2KCzGM07wCNv57y4f6gEnBFJtUVk8kd8EC3Pqiws="
Jan 12 23:45:11 volumio go-librespot[4075]: time="2026-01-12T23:45:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:45:11 volumio go-librespot[4075]: time="2026-01-12T23:45:11-06:00" level=debug msg="completed keyexchange"
Jan 12 23:45:11 volumio go-librespot[4075]: time="2026-01-12T23:45:11-06:00" level=debug msg="completed challenge"
Jan 12 23:45:11 volumio go-librespot[4075]: time="2026-01-12T23:45: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 "
Jan 12 23:45:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:45:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:45:11 volumio volumio[3952]: info: Plugin calmradio is not enabled
Jan 12 23:45:11 volumio volumio[3952]: info: Loading plugin "soundcloud"...
Jan 12 23:45:11 volumio volumio[3952]: info: Loading plugin "spop"...
Jan 12 23:45:11 volumio kernel: hwmon hwmon1: Voltage normalised
Jan 12 23:45:12 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.79.199
Jan 12 23:45:12 volumio avahi-daemon[664]: Registering new address record for 169.254.79.199 on eth0.IPv4.
Jan 12 23:45:12 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:45:12 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:12 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:12 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:12 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.79.199
Jan 12 23:45:12 volumio volumio[3952]: info: Loading plugin "squeezelite_mc"...
Jan 12 23:45:12 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.79.199
Jan 12 23:45:12 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.79.199
Jan 12 23:45:12 volumio avahi-daemon[664]: Withdrawing address record for 169.254.79.199 on eth0.
Jan 12 23:45:12 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:45:12 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:45:12 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:12 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:12 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:13 volumio volumio[3952]: info: Loading plugin "youtube2"...
Jan 12 23:45:14 volumio volumio[3952]: info: Loading plugin "ytcr"...
Jan 12 23:45:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55.
Jan 12 23:45:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:14 volumio go-librespot[4120]: go-librespot daemon starting...
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-06:00" level=debug msg="app state loaded"
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-06:00" level=debug msg="stored credentials not found"
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-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]"
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-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]"
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-06:00" level=info msg="zeroconf server listening on port 38183"
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-06:00" level=debug msg="obtained new client token: AAAhJXvZoyl2DUb1dnUcnsuVYBVayIV8/O4IFeqiV1bznQQc5/7fvWC1QXnAwga48yMzLHkBo9iA7mX8SIFNtqLcrR5QiJe9Wq1GqC2ROdHsHkC7RO3OdRVZL8Lh5YSRLgVsdjkkWu0Oo3W27Omr3s8C7Wx6Y+93hju82p1tR+zLpOMKRDgjJcOeEqKaQmK+wvPVEiUVPu/wHJpoJSl4BwxQTDpxIKGukl3bfQtGu3HgHmtC94V5HW6EPw=="
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-06:00" level=debug msg="completed keyexchange"
Jan 12 23:45:14 volumio go-librespot[4121]: time="2026-01-12T23:45:14-06:00" level=debug msg="completed challenge"
Jan 12 23:45:15 volumio go-librespot[4121]: time="2026-01-12T23:45: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 "
Jan 12 23:45:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:45:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:45:15 volumio volumio[3952]: info: Loading plugin "ytmusic"...
Jan 12 23:45:16 volumio volumio[3952]: info: Plugin now_playing is not enabled
Jan 12 23:45:16 volumio volumio[3952]: info: Loading plugin "outputs"...
Jan 12 23:45:16 volumio volumio[3952]: info: Loading plugin "albumart"...
Jan 12 23:45:16 volumio volumio[3952]: info: Plugin example_plugin is not enabled
Jan 12 23:45:16 volumio volumio[3952]: info: Loading plugin "inputs"...
Jan 12 23:45:16 volumio volumio[3952]: info: Loading plugin "updater_comm"...
Jan 12 23:45:16 volumio volumio[3952]: info: Plugin mpdemulation is not enabled
Jan 12 23:45:16 volumio volumio[3952]: info: Loading plugin "rest_api"...
Jan 12 23:45:16 volumio volumio[3952]: info: Loading plugin "websocket"...
Jan 12 23:45:16 volumio volumio[3952]: info: Starting Socket.io Server version 1.7.4
Jan 12 23:45:16 volumio volumio[3952]: info: Plugin fusiondsp is not enabled
Jan 12 23:45:16 volumio volumio[3952]: info: Plugin mpdoutput is not enabled
Jan 12 23:45:16 volumio volumio[3952]: info: Plugin RoonBridge is not enabled
Jan 12 23:45:16 volumio volumio[3952]: info: Loading plugin "podcast"...
Jan 12 23:45:16 volumio volumio[3952]: info: ControllerPodcast::constructor
Jan 12 23:45:16 volumio volumio[3952]: info: Loading plugin "volusonic"...
Jan 12 23:45:16 volumio volumio[4130]: Forking 3 albumart workers
Jan 12 23:45:17 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.27.161
Jan 12 23:45:17 volumio avahi-daemon[664]: Registering new address record for 169.254.27.161 on eth0.IPv4.
Jan 12 23:45:17 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:45:17 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:17 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:17 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:17 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.27.161
Jan 12 23:45:17 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.27.161
Jan 12 23:45:17 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.27.161
Jan 12 23:45:17 volumio avahi-daemon[664]: Withdrawing address record for 169.254.27.161 on eth0.
Jan 12 23:45:17 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:45:17 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:17 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:17 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:17 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:45:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56.
Jan 12 23:45:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:18 volumio volumio[4155]: Starting albumart workers
Jan 12 23:45:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:18 volumio go-librespot[4216]: go-librespot daemon starting...
Jan 12 23:45:18 volumio go-librespot[4217]: time="2026-01-12T23:45:18-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:45:18 volumio go-librespot[4217]: time="2026-01-12T23:45:18-06:00" level=debug msg="app state loaded"
Jan 12 23:45:18 volumio go-librespot[4217]: time="2026-01-12T23:45:18-06:00" level=debug msg="stored credentials not found"
Jan 12 23:45:18 volumio go-librespot[4217]: time="2026-01-12T23:45:18-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:45:18 volumio volumio[4154]: Starting albumart workers
Jan 12 23:45:18 volumio volumio[3952]: info: Applying required configuration parameters for plugin volusonic
Jan 12 23:45:18 volumio volumio[3952]: info: Loading plugin "backup_restore"...
Jan 12 23:45:18 volumio volumio[4156]: Starting albumart workers
Jan 12 23:45:19 volumio go-librespot[4217]: time="2026-01-12T23:45: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]"
Jan 12 23:45:19 volumio go-librespot[4217]: time="2026-01-12T23:45: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]"
Jan 12 23:45:19 volumio go-librespot[4217]: time="2026-01-12T23:45: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]"
Jan 12 23:45:19 volumio go-librespot[4217]: time="2026-01-12T23:45:19-06:00" level=info msg="zeroconf server listening on port 39889"
Jan 12 23:45:19 volumio volumio[3952]: info: Applying required configuration parameters for plugin backup_restore
Jan 12 23:45:19 volumio volumio[3952]: info: Plugin rpi_eeprom_config is not enabled
Jan 12 23:45:19 volumio volumio[3952]: info: Plugin rpi_eeprom_updater is not enabled
Jan 12 23:45:19 volumio volumio[3952]: info: Loading plugin "scheduledrestart"...
Jan 12 23:45:19 volumio volumio-remote-updater[14193]: [2026-01-12 23:45:19] [connect] Successful connection
Jan 12 23:45:19 volumio go-librespot[4217]: time="2026-01-12T23:45:19-06:00" level=debug msg="obtained new client token: AAADWTJHrzL4IP13on84KTCjHfeXr8A9DLBAPP/YSZewVUQMNgeX2pSMuwvB7GNugT447Ft4ey+VNPB9dnWRV2uE+di2qBWoMHfIXyuljifvjwZku8WmJOfVgye2++b5XYamnp7EN+/d4ruQT708a/vUryNPsMrbZ/+ilDFwgipl/QdO41eNR68l1QMo1hQoL5ITTz6o2kNmxNVHgVAGNPJf2yjHbfdJPYa5lXCB3gSJWd+6HpW77js="
Jan 12 23:45:19 volumio go-librespot[4217]: time="2026-01-12T23:45:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:45:19 volumio go-librespot[4217]: time="2026-01-12T23:45:19-06:00" level=debug msg="completed keyexchange"
Jan 12 23:45:19 volumio go-librespot[4217]: time="2026-01-12T23:45:19-06:00" level=debug msg="completed challenge"
Jan 12 23:45:19 volumio go-librespot[4217]: time="2026-01-12T23:45: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 "
Jan 12 23:45:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:45:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:45:19 volumio volumio[3952]: info: Applying required configuration parameters for plugin scheduledrestart
Jan 12 23:45:19 volumio volumio[3952]: info: Plugin Bluetoothremote is not enabled
Jan 12 23:45:19 volumio volumio[3952]: info: Plugin music_services_shield is not enabled
Jan 12 23:45:19 volumio volumio[3952]: info: Loading plugin "Systeminfo"...
Jan 12 23:45:20 volumio volumio[3952]: info: Plugin peppymeterbasic is not enabled
Jan 12 23:45:20 volumio volumio[3952]: info: Loading plugin "peppyspectrum"...
Jan 12 23:45:20 volumio kernel: hwmon hwmon1: Undervoltage detected!
Jan 12 23:45:20 volumio volumio[3952]: info: Loading i18n strings for locale en
Jan 12 23:45:20 volumio volumio[3952]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Jan 12 23:45:20 volumio volumio[3952]: Updating browse sources language
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::initPlayerControls
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:20 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 12 23:45:20 volumio volumio[3952]: Express server listening on port 3000
Jan 12 23:45:20 volumio volumio[3952]: [Metrics] WebUI: 17s 444.03ms
Jan 12 23:45:21 volumio volumio[3952]: info: CoreStateMachine::resetVolumioState
Jan 12 23:45:21 volumio volumio[3952]: info: CoreStateMachine::getcurrentVolume
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::volumioRetrievevolume
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:45:21 volumio sudo[4248]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jan 12 23:45:21 volumio sudo[4248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:21 volumio sudo[4250]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jan 12 23:45:21 volumio sudo[4250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:21 volumio sudo[4250]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:21 volumio sudo[4248]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:21 volumio volumio[3952]: info: Volumio Network Manager: Network status updated: 1
Jan 12 23:45:21 volumio volumio[3952]: info: VolumeController:: Volume=100 Mute =false
Jan 12 23:45:21 volumio volumio[3952]: info: CoreStateMachine::pushState
Jan 12 23:45:21 volumio volumio[3952]: info: CorePlayQueue::getTrack 0
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::volumioPushState
Jan 12 23:45:21 volumio volumio[3952]: info: CoreStateMachine::updateTrackBlock
Jan 12 23:45:21 volumio volumio[3952]: info: CorePlayQueue::getTrackBlock
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::volumioRetrievevolume
Jan 12 23:45:21 volumio volumio-remote-updater[14193]: [2026-01-12 23:45:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768283119 101
Jan 12 23:45:21 volumio volumio[3952]: 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
Jan 12 23:45:21 volumio volumio[3952]: info: Reloading queue from file
Jan 12 23:45:21 volumio volumio[3952]: info: CoreStateMachine::setRepeat null single undefined
Jan 12 23:45:21 volumio volumio[3952]: info: CoreStateMachine::pushState
Jan 12 23:45:21 volumio volumio[3952]: info: CorePlayQueue::getTrack 0
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::volumioPushState
Jan 12 23:45:21 volumio volumio[3952]: info: CoreStateMachine::setRandom null
Jan 12 23:45:21 volumio volumio[3952]: info: CoreStateMachine::pushState
Jan 12 23:45:21 volumio volumio[3952]: info: CorePlayQueue::getTrack 0
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::volumioPushState
Jan 12 23:45:21 volumio volumio[3952]: info: Setting Device type: Raspberry PI
Jan 12 23:45:21 volumio volumio[3952]: info: VolumeController:: Volume=100 Mute =false
Jan 12 23:45:21 volumio volumio[3952]: info: CoreStateMachine::pushState
Jan 12 23:45:21 volumio volumio[3952]: info: CorePlayQueue::getTrack 0
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::volumioPushState
Jan 12 23:45:21 volumio volumio[3952]: info: Completed loading Core Plugins
Jan 12 23:45:21 volumio volumio[3952]: info: Preparing to generate the ALSA configuration file
Jan 12 23:45:21 volumio sudo[4264]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Jan 12 23:45:21 volumio sudo[4264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:21 volumio volumio[3952]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954
Jan 12 23:45:21 volumio volumio[3952]: info: Discovery: Found device Volumio
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::volumioGetState
Jan 12 23:45:21 volumio volumio[3952]: info: CorePlayQueue::getTrack 0
Jan 12 23:45:21 volumio volumio[3952]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954
Jan 12 23:45:21 volumio volumio[3952]: info: Discovery: Found device Volumio
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::volumioGetState
Jan 12 23:45:21 volumio volumio[3952]: info: CorePlayQueue::getTrack 0
Jan 12 23:45:21 volumio volumio[3952]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Jan 12 23:45:21 volumio volumio[3952]: info: Reading ALSA contributions from plugins.
Jan 12 23:45:21 volumio volumio[3952]: info: Asound.conf file unchanged, so no further update is needed
Jan 12 23:45:21 volumio volumio[3952]: info: Output device has changed, restarting MPD
Jan 12 23:45:21 volumio sudo[4264]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:21 volumio volumio[3952]: info: Output device has changed, restarting Shairport Sync
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:45:21 volumio sudo[4267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jan 12 23:45:21 volumio sudo[4267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:21 volumio sudo[4269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jan 12 23:45:21 volumio sudo[4267]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:21 volumio sudo[4269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:21 volumio volumio[3952]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jan 12 23:45:21 volumio volumio[3952]: info: ___________ START PLUGINS ___________
Jan 12 23:45:21 volumio volumio[3952]: info: ControllerMpd::onStart: Initializing MPD
Jan 12 23:45:21 volumio volumio[3952]: info: Creating MPD Configuration file
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 12 23:45:21 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:45:21 volumio volumio[3952]: info: [1768283121910] CoreMusicLibrary::Adding element Media Servers
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:21 volumio sudo[4277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jan 12 23:45:21 volumio sudo[4277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:21 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.81.176
Jan 12 23:45:21 volumio avahi-daemon[664]: Registering new address record for 169.254.81.176 on eth0.IPv4.
Jan 12 23:45:21 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:45:21 volumio sudo[4279]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jan 12 23:45:21 volumio sudo[4279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:21 volumio sudo[4277]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:21 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:45:22 volumio volumio[3952]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:45:22 volumio systemd[1]: mpd.service: Deactivated successfully.
Jan 12 23:45:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Jan 12 23:45:22 volumio systemd[1]: mpd.service: Consumed 5.698s CPU time.
Jan 12 23:45:22 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:22 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:22 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:22 volumio systemd[1]: mpd.socket: Deactivated successfully.
Jan 12 23:45:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Jan 12 23:45:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Jan 12 23:45:22 volumio volumio[3952]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:45:22 volumio volumio[3952]: info: [1768283122065] CoreMusicLibrary::Adding element Last_100
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:45:22 volumio volumio[3952]: info: [1768283122073] CoreMusicLibrary::Adding element Webradio
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jan 12 23:45:22 volumio volumio[3952]: info: Initializing BBC Radios
Jan 12 23:45:22 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Jan 12 23:45:22 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:45:22 volumio volumio[3952]: info: [1768283122169] CoreMusicLibrary::Adding element Bandcamp Discover
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Bandcamp Discover
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:45:22 volumio volumio[3952]: info: [1768283122181] CoreMusicLibrary::Adding element SoundCloud
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Bandcamp Discover
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source SoundCloud
Jan 12 23:45:22 volumio volumio[3952]: info: Creating Spotify config file
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:22 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.81.176
Jan 12 23:45:22 volumio sudo[4315]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Jan 12 23:45:22 volumio sudo[4315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Jan 12 23:45:22 volumio sudo[4315]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57.
Jan 12 23:45:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:22 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.81.176
Jan 12 23:45:22 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.81.176
Jan 12 23:45:22 volumio go-librespot[4323]: go-librespot daemon starting...
Jan 12 23:45:22 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:45:22 volumio avahi-daemon[664]: Withdrawing address record for 169.254.81.176 on eth0.
Jan 12 23:45:22 volumio go-librespot[4324]: time="2026-01-12T23:45:22-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:45:22 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:22 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:22 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
Jan 12 23:45:22 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:22 volumio volumio[3952]: info: [squeezelite_mc] Starting proxy server...
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:45:22 volumio volumio[3952]: info: [1768283122597] CoreMusicLibrary::Adding element YouTube2
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Bandcamp Discover
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source SoundCloud
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube2
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:45:22 volumio volumio[3952]: info: [1768283122618] CoreMusicLibrary::Adding element YouTube Music
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Bandcamp Discover
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source SoundCloud
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube2
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube Music
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:45:22 volumio volumio[3952]: info: [1768283122643] CoreMusicLibrary::Adding element Podcast
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Bandcamp Discover
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source SoundCloud
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube2
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube Music
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Podcast
Jan 12 23:45:22 volumio volumio[3952]: info: Loading i18n strings for locale en
Jan 12 23:45:22 volumio volumio[3952]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Jan 12 23:45:22 volumio volumio[3952]: Updating browse sources language
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Bandcamp Discover
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source SoundCloud
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube2
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube Music
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Podcast
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Bandcamp Discover
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source SoundCloud
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube2
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube Music
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Podcast
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:45:22 volumio volumio[3952]: info: [1768283122705] CoreMusicLibrary::Adding element Volusonic
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Bandcamp Discover
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source SoundCloud
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube2
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source YouTube Music
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Podcast
Jan 12 23:45:22 volumio volumio[3952]: Cannot find translation for source Volusonic
Jan 12 23:45:22 volumio volumio[3952]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Jan 12 23:45:22 volumio volumio[3952]: info: Volumio Calling Home
Jan 12 23:45:22 volumio go-librespot[4324]: time="2026-01-12T23:45:22-06:00" level=info msg="zeroconf server listening on port 38065"
Jan 12 23:45:22 volumio volumio[3952]: info: [squeezelite_mc] Proxy server started on port 44935
Jan 12 23:45:22 volumio volumio[3952]: info: Preparing to generate the ALSA configuration file
Jan 12 23:45:22 volumio volumio[3952]: info: CoreCommandRouter::volumioRetrievevolume
Jan 12 23:45:23 volumio volumio[3952]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Jan 12 23:45:23 volumio volumio[3952]: info: Reading ALSA contributions from plugins.
Jan 12 23:45:23 volumio volumio[3952]: info: MPD Permissions set
Jan 12 23:45:23 volumio volumio[3952]: info: MPD Permissions set
Jan 12 23:45:23 volumio volumio[3952]: info: Upmpdcli Daemon Started
Jan 12 23:45:23 volumio volumio[3952]: info: Spotify config file written
Jan 12 23:45:23 volumio sudo[4353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Jan 12 23:45:23 volumio sudo[4353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:23 volumio volumio[3952]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Jan 12 23:45:23 volumio volumio[3952]: info: VolumeController:: Volume=100 Mute =false
Jan 12 23:45:23 volumio volumio[3952]: info: CoreStateMachine::pushState
Jan 12 23:45:23 volumio volumio[3952]: info: CorePlayQueue::getTrack 0
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::volumioPushState
Jan 12 23:45:23 volumio volumio[3952]: info: [squeezelite_mc] Server discovery started
Jan 12 23:45:23 volumio volumio[3952]: info: [squeezelite_mc] Player finder started
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Jan 12 23:45:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Jan 12 23:45:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: No need to fix Spotify hosts
Jan 12 23:45:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:23 volumio go-librespot[4362]: go-librespot daemon starting...
Jan 12 23:45:23 volumio sudo[4353]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45:23-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45:23-06:00" level=debug msg="app state loaded"
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45:23-06:00" level=debug msg="stored credentials not found"
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45:23-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:45:23 volumio volumio[3952]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Jan 12 23:45:23 volumio volumio[3952]: info: Volumio called home
Jan 12 23:45:23 volumio volumio[3952]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"]
Jan 12 23:45:23 volumio volumio[3952]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"}
Jan 12 23:45:23 volumio volumio[3952]: 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
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45: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]"
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45: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]"
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45: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]"
Jan 12 23:45:23 volumio volumio[3952]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Jan 12 23:45:23 volumio volumio[3952]: SPOTIFY: BQCli1A_r7fCuodZg1N3FsY1veF9YicK4uV7w1jm9Y09epXtlaQcM4f3z0PPmwZChPPCbbjT41LuZN28gyOSSFyaPenYKpinch0BdRnO2cIQtQOz6CjgyVcJ-R_FPMWIkMBKdF6ZPUqgn89WXKFjBFwnbO1RCRr8bFixCA0Sbb8_4_deIWoIi8RJ-iuzWjrCRNGKTusgQBwOJWdztwxYZZkA7YXx8t7ZJEbvKsY
Jan 12 23:45:23 volumio volumio[3952]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Jan 12 23:45:23 volumio volumio[3952]: info: New Spotify access token = BQCli1A_r7fCuodZg1N3FsY1veF9YicK4uV7w1jm9Y09epXtlaQcM4f3z0PPmwZChPPCbbjT41LuZN28gyOSSFyaPenYKpinch0BdRnO2cIQtQOz6CjgyVcJ-R_FPMWIkMBKdF6ZPUqgn89WXKFjBFwnbO1RCRr8bFixCA0Sbb8_4_deIWoIi8RJ-iuzWjrCRNGKTusgQBwOJWdztwxYZZkA7YXx8t7ZJEbvKsY
Jan 12 23:45:23 volumio volumio[3952]: info: Spotify credentials grant success - running version from March 24, 2019
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45:23-06:00" level=info msg="zeroconf server listening on port 40359"
Jan 12 23:45:23 volumio volumio[3952]: info: Starting Shairport Sync
Jan 12 23:45:23 volumio volumio[3952]: info: Starting Shairport Sync
Jan 12 23:45:23 volumio volumio[3952]: info: Starting Shairport Sync
Jan 12 23:45:23 volumio sudo[4382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jan 12 23:45:23 volumio sudo[4382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45:23-06:00" level=debug msg="obtained new client token: AABd03iixaCsq5la5Csq4Bf/WXcXQN34HlZSdGM+5pZwu8VgTBs3CLx67oLhYqJVnkYWQhLyxgQK1+HgzJHZaoZhKyyO6h6kKgtkZoTO/ZL/cXWdnH/vAGTaO9c9xLqgc6yZYwsA6vKPZ5ic7d5gvO9fpu7fTG4mO++ZYJijzwDgRqFmYFbBuqKJmHp7lXnOpQed6O0oYEGeeC1VPXnATzYTaTRAnIJTclhr2prLNnwVmwAK3gMnqUEa0Q=="
Jan 12 23:45:23 volumio sudo[4386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jan 12 23:45:23 volumio sudo[4386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:23 volumio sudo[4385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jan 12 23:45:23 volumio sudo[4385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Jan 12 23:45:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Jan 12 23:45:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:45:23 volumio systemd[1]: shairport-sync.service: Consumed 1.988s CPU time.
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:45:23 volumio sudo[4379]: 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
Jan 12 23:45:23 volumio sudo[4379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:23 volumio sudo[4379]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45:23-06:00" level=debug msg="completed keyexchange"
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45:23-06:00" level=debug msg="completed challenge"
Jan 12 23:45:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:45:23 volumio go-librespot[4369]: time="2026-01-12T23:45:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials "
Jan 12 23:45:23 volumio sudo[4382]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:45:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:45:23 volumio volumio[3952]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Jan 12 23:45:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Jan 12 23:45:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Jan 12 23:45:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:45:23 volumio volumio[3952]: info: Asound.conf file unchanged, so no further update is needed
Jan 12 23:45:23 volumio volumio[3952]: info: Output device has changed, restarting MPD
Jan 12 23:45:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:45:23 volumio sudo[4385]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:23 volumio sudo[4386]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:23 volumio volumio[3952]: info: Output device has changed, restarting Shairport Sync
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:23 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:45:24 volumio sudo[4395]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Jan 12 23:45:24 volumio sudo[4395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:24 volumio sudo[4402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jan 12 23:45:24 volumio sudo[4402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:24 volumio volumio[3952]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jan 12 23:45:24 volumio sudo[4395]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:24 volumio sudo[4398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jan 12 23:45:24 volumio sudo[4398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:24 volumio sudo[4398]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:24 volumio systemd[1]: mpd.service: Deactivated successfully.
Jan 12 23:45:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Jan 12 23:45:24 volumio systemd[1]: mpd.service: Consumed 1.768s CPU time.
Jan 12 23:45:24 volumio systemd[1]: mpd.socket: Deactivated successfully.
Jan 12 23:45:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Jan 12 23:45:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Jan 12 23:45:24 volumio volumio[3952]: info: Shairport-Sync Started
Jan 12 23:45:24 volumio volumio[3952]: Error adding Membership: Error: addMembership EINVAL
Jan 12 23:45:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Jan 12 23:45:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Jan 12 23:45:24 volumio volumio[3952]: info: MPD Permissions set
Jan 12 23:45:24 volumio volumio[3952]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Jan 12 23:45:24 volumio volumio[3952]: info: Shairport-Sync Started
Jan 12 23:45:24 volumio volumio[3952]: info: Shairport-Sync Started
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:24 volumio sudo[4429]: 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
Jan 12 23:45:24 volumio sudo[4429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::volumioGetState
Jan 12 23:45:24 volumio volumio[3952]: info: CorePlayQueue::getTrack 0
Jan 12 23:45:24 volumio sudo[4429]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:24 volumio sudo[4426]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Jan 12 23:45:24 volumio sudo[4426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Jan 12 23:45:24 volumio volumio[3952]: 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"}
Jan 12 23:45:24 volumio kernel: hwmon hwmon1: Voltage normalised
Jan 12 23:45:24 volumio volumio[3952]: info: Spotify Successfully logged in
Jan 12 23:45:24 volumio sudo[4426]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jan 12 23:45:24 volumio volumio[3952]: info: [1768283124499] CoreMusicLibrary::Adding element Spotify
Jan 12 23:45:24 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jan 12 23:45:24 volumio volumio[3952]: Cannot find translation for source Bandcamp Discover
Jan 12 23:45:24 volumio volumio[3952]: Cannot find translation for source SoundCloud
Jan 12 23:45:24 volumio volumio[3952]: Cannot find translation for source YouTube2
Jan 12 23:45:24 volumio volumio[3952]: Cannot find translation for source YouTube Music
Jan 12 23:45:24 volumio volumio[3952]: Cannot find translation for source Podcast
Jan 12 23:45:24 volumio volumio[3952]: Cannot find translation for source Volusonic
Jan 12 23:45:24 volumio volumio[3952]: Cannot find translation for source Spotify
Jan 12 23:45:24 volumio volumio[3952]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true
Jan 12 23:45:24 volumio volumio[3952]: info: Starting Shairport Sync
Jan 12 23:45:24 volumio sudo[4440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Jan 12 23:45:24 volumio sudo[4440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:24 volumio sudo[4442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Jan 12 23:45:24 volumio sudo[4442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:24 volumio systemd[1]: Reloading.
Jan 12 23:45:25 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:25 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:25 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 12 23:45:25 volumio volumio[3952]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 12 23:45:26 volumio volumio[3952]: info: go-librespot daemon successfully initialized
Jan 12 23:45:26 volumio kernel: hwmon hwmon1: Undervoltage detected!
Jan 12 23:45:27 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.
Jan 12 23:45:27 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.
Jan 12 23:45:27 volumio volumio[3952]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jan 12 23:45:27 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.125.7
Jan 12 23:45:27 volumio avahi-daemon[664]: Registering new address record for 169.254.125.7 on eth0.IPv4.
Jan 12 23:45:27 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16
Jan 12 23:45:27 volumio volumio[3952]: Error: addMembership ENODEV
Jan 12 23:45:27 volumio volumio[3952]: at Socket.addMembership (node:dgram:860:11)
Jan 12 23:45:27 volumio volumio[3952]: at addMembership (/volumio/node_modules/node-ssdp/lib/index.js:264:16) {
Jan 12 23:45:27 volumio volumio[3952]: errno: -19,
Jan 12 23:45:27 volumio volumio[3952]: code: 'ENODEV',
Jan 12 23:45:27 volumio volumio[3952]: syscall: 'addMembership'
Jan 12 23:45:27 volumio volumio[3952]: }
Jan 12 23:45:27 volumio volumio[3952]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jan 12 23:45:28 volumio sudo[4440]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Jan 12 23:45:28 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:28 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:28 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jan 12 23:45:28 volumio go-librespot[4504]: go-librespot daemon starting...
Jan 12 23:45:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Jan 12 23:45:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Jan 12 23:45:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:45:28 volumio systemd[1]: shairport-sync.service: Consumed 1.408s CPU time.
Jan 12 23:45:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Jan 12 23:45:28 volumio sudo[4442]: pam_unix(sudo:session): session closed for user root
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-06:00" level=info msg="running go-librespot 0.4.0"
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-06:00" level=debug msg="app state loaded"
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-06:00" level=debug msg="stored credentials not found"
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Jan 12 23:45:28 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.125.7
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45: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-gew4.spotify.com:80]"
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-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]"
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-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]"
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-06:00" level=info msg="zeroconf server listening on port 36567"
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-06:00" level=debug msg="obtained new client token: AADBl8baQ5qbaXC2AXNQXF9esZnXVK4ZSEQYPQH27Ahnn4IQQvKSf1lzB6krUMmN1K7udEuDSLKIeF34pIeBK07i22jZkGTiHX4U2JXkJm9lmV86Qxntz6OKRnCOiVv5q0JDF6HjRfLwP1b6+tdmMUgU1GQOyBp3dQBsaA9oc+SxYZLOrfpRZQDoQN4POvt3ZVS2YsFcOFST46yWmHkdrKkNEPjBasaAFjAEQUkNJQ4SmErW31/1V/Qgpg=="
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-06:00" level=debug msg="completed keyexchange"
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45:28-06:00" level=debug msg="completed challenge"
Jan 12 23:45:28 volumio go-librespot[4506]: time="2026-01-12T23:45: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 "
Jan 12 23:45:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jan 12 23:45:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jan 12 23:45:29 volumio sudo[4530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-12 23:44'
Jan 12 23:45:29 volumio sudo[4530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jan 12 23:45:29 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.125.7
Jan 12 23:45:29 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.125.7
Jan 12 23:45:29 volumio avahi-daemon[664]: Withdrawing address record for 169.254.125.7 on eth0.
Jan 12 23:45:29 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16
Jan 12 23:45:29 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:29 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Jan 12 23:45:29 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Jan 12 23:45:29 volumio dhcpcd[684]: eth0: probing for an IPv4LL address
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"