Dec 30 06:20:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.63.225 Dec 30 06:20:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 30 06:20:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:00 volumio go-librespot[19021]: go-librespot daemon starting... Dec 30 06:20:00 volumio go-librespot[19022]: time="2025-12-30T06:20:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:00 volumio go-librespot[19022]: time="2025-12-30T06:20:00-06:00" level=debug msg="app state loaded" Dec 30 06:20:00 volumio go-librespot[19022]: time="2025-12-30T06:20:00-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:00 volumio go-librespot[19022]: time="2025-12-30T06:20:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:00 volumio sudo[19029]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 06:20:00 volumio sudo[19029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:00 volumio sudo[19031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 06:20:00 volumio sudo[19031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:00 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 30 06:20:00 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 30 06:20:00 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 30 06:20:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.63.225 Dec 30 06:20:00 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.63.225 Dec 30 06:20:00 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:00 volumio avahi-daemon[664]: Withdrawing address record for 169.254.63.225 on eth0. Dec 30 06:20:00 volumio volumio[18333]: info: Initializing connection to go-librespot Websocket Dec 30 06:20:00 volumio go-librespot[19022]: time="2025-12-30T06:20:00-06:00" level=debug msg="new websocket client" Dec 30 06:20:00 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:00 volumio volumio[18333]: info: Connection to go-librespot Websocket established Dec 30 06:20:00 volumio sudo[19048]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 06:20:00 volumio sudo[19048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:00 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 30 06:20:00 volumio sudo[19029]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:00 volumio sudo[19031]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:00 volumio mpd_monitor.sh[19034]: MPD Monitor Service: Starting MPD Monitor Service Dec 30 06:20:00 volumio volumio[18333]: info: Successfully started MPD Monitor Dec 30 06:20:00 volumio volumio[18333]: info: Successfully started MPD Monitor Dec 30 06:20:01 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:01 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:01 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:01 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 30 06:20:01 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 30 06:20:01 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 30 06:20:01 volumio go-librespot[19022]: time="2025-12-30T06:20:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:20:01 volumio go-librespot[19022]: time="2025-12-30T06:20:01-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]" Dec 30 06:20:01 volumio go-librespot[19022]: time="2025-12-30T06:20:01-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]" Dec 30 06:20:01 volumio go-librespot[19022]: time="2025-12-30T06:20:01-06:00" level=info msg="zeroconf server listening on port 46585" Dec 30 06:20:01 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 30 06:20:01 volumio sudo[19048]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:01 volumio mpd_monitor.sh[19059]: MPD Monitor Service: Starting MPD Monitor Service Dec 30 06:20:01 volumio volumio[18333]: info: Successfully started MPD Monitor Dec 30 06:20:01 volumio go-librespot[19022]: time="2025-12-30T06:20:01-06:00" level=debug msg="obtained new client token: AAAv+QvSZR6DUKPaJS9YHPwjPFFbf3ntAO1mNJeUME44OOUS47Q5ikCla4XdBX91i0ewlP8XAHOedQu8iScLjgWK6HEgLIBKV8gnxTwgs8h/M1c2R5WU4kpcUJ8btBuw9id5CMxvKvXoW47gaptzg9XkdUCeVc3nvUCwpqrodyvMMoaryKrOyBcCGDCPrGVzJnf/LUxa21Q0WMwJw7VvA7zi/WNYvYsSCE/JdS0aHcg14GIkPgyWa94=" Dec 30 06:20:01 volumio go-librespot[19022]: time="2025-12-30T06:20:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:03 volumio go-librespot[19022]: time="2025-12-30T06:20:03-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:03 volumio go-librespot[19022]: time="2025-12-30T06:20:03-06:00" level=debug msg="completed challenge" Dec 30 06:20:03 volumio go-librespot[19022]: time="2025-12-30T06:20: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 " Dec 30 06:20:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:03 volumio volumio[18333]: info: Connection to go-librespot Websocket closed Dec 30 06:20:03 volumio volumio[18333]: info: Getting Spotify volume Dec 30 06:20:04 volumio volumio[18333]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 06:20:04 volumio volumio[18333]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 06:20:04 volumio volumio[18333]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 30 06:20:04 volumio volumio[18333]: errno: -111, Dec 30 06:20:04 volumio volumio[18333]: code: 'ECONNREFUSED', Dec 30 06:20:04 volumio volumio[18333]: syscall: 'connect', Dec 30 06:20:04 volumio volumio[18333]: address: '127.0.0.1', Dec 30 06:20:04 volumio volumio[18333]: port: 9879, Dec 30 06:20:04 volumio volumio[18333]: response: undefined Dec 30 06:20:04 volumio volumio[18333]: } Dec 30 06:20:04 volumio volumio[18333]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 06:20:05 volumio sudo[19079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-30 06:19' Dec 30 06:20:05 volumio sudo[19079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:05 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 06:20:05 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.167.52 Dec 30 06:20:05 volumio avahi-daemon[664]: Registering new address record for 169.254.167.52 on eth0.IPv4. Dec 30 06:20:05 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:20:06 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:06 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:06 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:06 volumio sudo[19079]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:06 volumio volumio-remote-updater[702]: [2025-12-30 06:20:06] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 30 06:20:06 volumio volumio-remote-updater[702]: [2025-12-30 06:20:06] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 30 06:20:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 30 06:20:06 volumio systemd[1]: volumio.service: Consumed 50.139s CPU time. Dec 30 06:20:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 30 06:20:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 30 06:20:06 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 397. Dec 30 06:20:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 30 06:20:06 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 30 06:20:06 volumio systemd[1]: volumio.service: Consumed 50.139s CPU time. Dec 30 06:20:06 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 30 06:20:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 30 06:20:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.167.52 Dec 30 06:20:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 30 06:20:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.167.52 Dec 30 06:20:06 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.167.52 Dec 30 06:20:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:06 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:06 volumio avahi-daemon[664]: Withdrawing address record for 169.254.167.52 on eth0. Dec 30 06:20:06 volumio go-librespot[19123]: go-librespot daemon starting... Dec 30 06:20:06 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:06 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:06 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:06 volumio go-librespot[19126]: time="2025-12-30T06:20:06-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:06 volumio go-librespot[19126]: time="2025-12-30T06:20:06-06:00" level=debug msg="app state loaded" Dec 30 06:20:06 volumio go-librespot[19126]: time="2025-12-30T06:20:06-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:06 volumio go-librespot[19126]: time="2025-12-30T06:20:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:06 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:07 volumio go-librespot[19126]: time="2025-12-30T06:20:07-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 30 06:20:07 volumio go-librespot[19126]: time="2025-12-30T06:20:07-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]" Dec 30 06:20:07 volumio go-librespot[19126]: time="2025-12-30T06:20:07-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]" Dec 30 06:20:07 volumio go-librespot[19126]: time="2025-12-30T06:20:07-06:00" level=info msg="zeroconf server listening on port 36461" Dec 30 06:20:07 volumio go-librespot[19126]: time="2025-12-30T06:20:07-06:00" level=debug msg="obtained new client token: AADI9Mhj6ZP2fU6AnM97YIof4b25J7w309/MmWF1BqTmjS1ryzcmOnfNCjMiZLy+KYAQpZM6I8InJOVCibZTNViooPPjaxG8RC5Z3qpfiZ8HdHi9ACYDnwA+6fwkHB5sRCmR4Pn7qAP4uQm8hJbnqI+1mcv6usxaubW3keLybZKSHq6jSSlrARr83/inHNOZ9Nl+S42YCS7dAF/g1MmDsLnklgQw1n7zn+rng43+RXra6p359sHyE/A=" Dec 30 06:20:07 volumio go-librespot[19126]: time="2025-12-30T06:20:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:07 volumio go-librespot[19126]: time="2025-12-30T06:20:07-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:07 volumio go-librespot[19126]: time="2025-12-30T06:20:07-06:00" level=debug msg="completed challenge" Dec 30 06:20:07 volumio go-librespot[19126]: time="2025-12-30T06:20: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 " Dec 30 06:20:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:08 volumio volumio[19108]: info: ------------------------------------------- Dec 30 06:20:08 volumio volumio[19108]: info: ----- Volumio3 ---- Dec 30 06:20:08 volumio volumio[19108]: info: ------------------------------------------- Dec 30 06:20:08 volumio volumio[19108]: info: ----- System startup ---- Dec 30 06:20:08 volumio volumio[19108]: info: ------------------------------------------- Dec 30 06:20:09 volumio volumio[19108]: info: MYVOLUMIO Environment detected Dec 30 06:20:09 volumio volumio[19108]: info: Plugin folders cleanup Dec 30 06:20:09 volumio volumio[19108]: info: Scanning into folder /volumio/app/plugins/ Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category audio_interface Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category miscellanea Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category music_service Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category plugins.json Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category system_controller Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category user_interface Dec 30 06:20:09 volumio volumio[19108]: info: Scanning into folder /data/plugins/ Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category audio_interface Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category music_service Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category system_controller Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category system_hardware Dec 30 06:20:09 volumio volumio[19108]: info: Scanning category user_interface Dec 30 06:20:09 volumio volumio[19108]: info: Plugin folders cleanup completed Dec 30 06:20:09 volumio volumio[19108]: info: ------------------------------------------- Dec 30 06:20:09 volumio volumio[19108]: info: ----- Core plugins startup ---- Dec 30 06:20:09 volumio volumio[19108]: info: ------------------------------------------- Dec 30 06:20:09 volumio volumio[19108]: info: Loading plugins from folder /volumio/app/plugins/ Dec 30 06:20:09 volumio volumio[19108]: info: Adding plugin upnp to MyMusic Plugins Dec 30 06:20:09 volumio volumio[19108]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 30 06:20:09 volumio volumio[19108]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 30 06:20:09 volumio volumio[19108]: info: Loading plugins from folder /data/plugins/ Dec 30 06:20:09 volumio volumio[19108]: info: Loading plugin "system"... Dec 30 06:20:09 volumio volumio[19108]: info: Loading plugin "appearance"... Dec 30 06:20:09 volumio kernel: hwmon hwmon1: Voltage normalised Dec 30 06:20:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Dec 30 06:20:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:10 volumio volumio[19108]: info: Loading plugin "network"... Dec 30 06:20:10 volumio volumio[19108]: info: Refreshing Cached IP Addresses Dec 30 06:20:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:10 volumio go-librespot[19161]: go-librespot daemon starting... Dec 30 06:20:10 volumio sudo[19163]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 06:20:10 volumio sudo[19163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:10 volumio sudo[19163]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:10 volumio sudo[19165]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 06:20:10 volumio sudo[19165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:10 volumio volumio[19108]: info: Loading plugin "services"... Dec 30 06:20:10 volumio go-librespot[19167]: time="2025-12-30T06:20:10-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:10 volumio go-librespot[19167]: time="2025-12-30T06:20:10-06:00" level=debug msg="app state loaded" Dec 30 06:20:10 volumio go-librespot[19167]: time="2025-12-30T06:20:10-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:10 volumio sudo[19165]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:10 volumio go-librespot[19167]: time="2025-12-30T06:20:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:10 volumio volumio[19108]: info: Loading plugin "alsa_controller"... Dec 30 06:20:10 volumio sudo[19178]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 30 06:20:10 volumio sudo[19178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:10 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 06:20:10 volumio volumio[19108]: info: Loading plugin "wizard"... Dec 30 06:20:10 volumio volumio[19108]: info: Loading plugin "networkfs"... Dec 30 06:20:10 volumio volumio[19108]: info: Starting Udev Watcher for removable devices Dec 30 06:20:11 volumio volumio[19108]: info: Ignoring mount for partition: boot Dec 30 06:20:11 volumio volumio[19108]: info: Ignoring mount for partition: volumio Dec 30 06:20:11 volumio volumio[19108]: info: Ignoring mount for partition: volumio_data Dec 30 06:20:11 volumio volumio[19108]: info: Mounting Device Wikipedia Dec 30 06:20:11 volumio sudo[19209]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Dec 30 06:20:11 volumio sudo[19209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:11 volumio go-librespot[19167]: time="2025-12-30T06:20: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]" Dec 30 06:20:11 volumio go-librespot[19167]: time="2025-12-30T06:20: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]" Dec 30 06:20:11 volumio go-librespot[19167]: time="2025-12-30T06:20: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]" Dec 30 06:20:11 volumio sudo[19209]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:11 volumio volumio[19108]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 30 06:20:11 volumio volumio[19108]: dmesg(1) may have more information after failed mount system call. Dec 30 06:20:11 volumio volumio[19108]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Dec 30 06:20:11 volumio volumio[19108]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 30 06:20:11 volumio volumio[19108]: dmesg(1) may have more information after failed mount system call. Dec 30 06:20:11 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 06:20:11 volumio volumio[19108]: info: Loading plugin "volumio_command_line_client"... Dec 30 06:20:11 volumio go-librespot[19167]: time="2025-12-30T06:20:11-06:00" level=info msg="zeroconf server listening on port 38089" Dec 30 06:20:11 volumio volumio[19108]: info: Loading plugin "upnp"... Dec 30 06:20:11 volumio volumio[19108]: info: [1767097211180] Starting Upmpd Daemon Dec 30 06:20:11 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 06:20:11 volumio volumio[19108]: info: Loading plugin "my_music"... Dec 30 06:20:11 volumio volumio[19108]: info: Loading plugin "mpd"... Dec 30 06:20:11 volumio volumio-remote-updater[702]: [2025-12-30 06:20:11] [connect] Successful connection Dec 30 06:20:11 volumio go-librespot[19167]: time="2025-12-30T06:20:11-06:00" level=debug msg="obtained new client token: AAADeWJ2sJ7/jYsSYU13gklzjSOVG+prGr+2adkKVFN7xDIDl+nUeiV6h8Lp66v5HKdAua7FjbYC/oOqZbPorzf2NoM5xKLnahbFsaQqRufkWlVihArUBFHmU21bhCYrZEC2dF2d3iNVgXFGs5ory+NHDVQTxQCd/UdY1lueEfXLSgbgD8/ej5bkYpbvGyk1N81fj+AsaDjwfS8kPqynvKl+hYyOQ2/HTq/gKJIzYj+I7DvY1U+ZKAQ=" Dec 30 06:20:11 volumio go-librespot[19167]: time="2025-12-30T06:20:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:11 volumio sudo[19178]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:11 volumio go-librespot[19167]: time="2025-12-30T06:20:11-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:11 volumio go-librespot[19167]: time="2025-12-30T06:20:11-06:00" level=debug msg="completed challenge" Dec 30 06:20:11 volumio go-librespot[19167]: time="2025-12-30T06:20: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 " Dec 30 06:20:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:11 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.200.33 Dec 30 06:20:11 volumio avahi-daemon[664]: Registering new address record for 169.254.200.33 on eth0.IPv4. Dec 30 06:20:11 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:20:11 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:11 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:11 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:11 volumio volumio[19108]: info: Loading plugin "upnp_browser"... Dec 30 06:20:11 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 06:20:12 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.200.33 Dec 30 06:20:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.200.33 Dec 30 06:20:13 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.200.33 Dec 30 06:20:13 volumio avahi-daemon[664]: Withdrawing address record for 169.254.200.33 on eth0. Dec 30 06:20:13 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:13 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:13 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:13 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:13 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:14 volumio volumio[19108]: info: Loading plugin "alarm-clock"... Dec 30 06:20:14 volumio volumio[19108]: info: Loading plugin "airplay_emulation"... Dec 30 06:20:14 volumio volumio[19108]: info: Starting Shairport Sync Dec 30 06:20:14 volumio volumio[19108]: info: Loading plugin "last_100"... Dec 30 06:20:14 volumio volumio[19108]: info: Loading plugin "webradio"... Dec 30 06:20:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Dec 30 06:20:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:14 volumio go-librespot[19243]: go-librespot daemon starting... Dec 30 06:20:14 volumio volumio[19108]: info: Loading plugin "i2s_dacs"... Dec 30 06:20:14 volumio volumio[19108]: info: I2S DAC not set, start Auto-detection Dec 30 06:20:14 volumio volumio[19108]: info: Loading plugin "volumiodiscovery"... Dec 30 06:20:14 volumio go-librespot[19244]: time="2025-12-30T06:20:14-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:14 volumio go-librespot[19244]: time="2025-12-30T06:20:14-06:00" level=debug msg="app state loaded" Dec 30 06:20:14 volumio go-librespot[19244]: time="2025-12-30T06:20:14-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:14 volumio go-librespot[19244]: time="2025-12-30T06:20:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:14 volumio volumio[19108]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 30 06:20:14 volumio volumio[19108]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 06:20:14 volumio volumio[19108]: *** WARNING *** For more information see Dec 30 06:20:14 volumio volumio[19108]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 30 06:20:14 volumio volumio[19108]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 06:20:14 volumio volumio[19108]: *** WARNING *** For more information see Dec 30 06:20:14 volumio node[19108]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 30 06:20:14 volumio node[19108]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 06:20:14 volumio node[19108]: *** WARNING *** For more information see Dec 30 06:20:14 volumio node[19108]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 30 06:20:14 volumio node[19108]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 06:20:14 volumio node[19108]: *** WARNING *** For more information see Dec 30 06:20:14 volumio volumio[19108]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 30 06:20:14 volumio volumio[19108]: info: Discovery: Started advertising with name: Volumio Dec 30 06:20:14 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 06:20:14 volumio volumio[19108]: info: Loading plugin "bandcamp"... Dec 30 06:20:15 volumio go-librespot[19244]: time="2025-12-30T06:20:15-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:20:15 volumio go-librespot[19244]: time="2025-12-30T06:20:15-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 06:20:15 volumio go-librespot[19244]: time="2025-12-30T06:20:15-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 06:20:15 volumio go-librespot[19244]: time="2025-12-30T06:20:15-06:00" level=info msg="zeroconf server listening on port 35769" Dec 30 06:20:15 volumio go-librespot[19244]: time="2025-12-30T06:20:15-06:00" level=debug msg="obtained new client token: AABEH6fKtn3W4QLYeRgR3YhvK1qPiSi4hW2plRmp9vf7F/BZcMfBYYnVtprEWQK3ooHXri4xZV9LXf6RiGiUtSMoMtpRc158rxx0CHwhudeJgXuSe1rrXcUA8FCv5kqLTNaYDfulF7Q8aT2nco454vE8DksvPUSy+zpcmLahZoJ79peVoiMLdph4Itjrp9EL7+wie1FCMmFM3pZvv9cX2R27DaY+b7ry+Hd51xBVNdJk07uCLuNvFN8=" Dec 30 06:20:15 volumio go-librespot[19244]: time="2025-12-30T06:20:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:15 volumio go-librespot[19244]: time="2025-12-30T06:20:15-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:15 volumio go-librespot[19244]: time="2025-12-30T06:20:15-06:00" level=debug msg="completed challenge" Dec 30 06:20:15 volumio go-librespot[19244]: time="2025-12-30T06:20: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 " Dec 30 06:20:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:16 volumio volumio[19108]: info: Plugin calmradio is not enabled Dec 30 06:20:16 volumio volumio[19108]: info: Loading plugin "soundcloud"... Dec 30 06:20:16 volumio volumio[19108]: info: Loading plugin "spop"... Dec 30 06:20:17 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.196.23 Dec 30 06:20:17 volumio avahi-daemon[664]: Registering new address record for 169.254.196.23 on eth0.IPv4. Dec 30 06:20:17 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:20:17 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:17 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:17 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:18 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.196.23 Dec 30 06:20:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Dec 30 06:20:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:18 volumio go-librespot[19270]: go-librespot daemon starting... Dec 30 06:20:18 volumio go-librespot[19271]: time="2025-12-30T06:20:18-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:18 volumio go-librespot[19271]: time="2025-12-30T06:20:18-06:00" level=debug msg="app state loaded" Dec 30 06:20:18 volumio go-librespot[19271]: time="2025-12-30T06:20:18-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:18 volumio go-librespot[19271]: time="2025-12-30T06:20:18-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:18 volumio volumio[19108]: info: Loading plugin "squeezelite_mc"... Dec 30 06:20:18 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.196.23 Dec 30 06:20:18 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.196.23 Dec 30 06:20:18 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:18 volumio avahi-daemon[664]: Withdrawing address record for 169.254.196.23 on eth0. Dec 30 06:20:18 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:18 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:18 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:18 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:19 volumio go-librespot[19271]: time="2025-12-30T06:20: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 30 06:20:19 volumio go-librespot[19271]: time="2025-12-30T06:20:19-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]" Dec 30 06:20:19 volumio go-librespot[19271]: time="2025-12-30T06:20:19-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]" Dec 30 06:20:19 volumio go-librespot[19271]: time="2025-12-30T06:20:19-06:00" level=info msg="zeroconf server listening on port 44261" Dec 30 06:20:19 volumio go-librespot[19271]: time="2025-12-30T06:20:19-06:00" level=debug msg="obtained new client token: AABc7fG0H6cHrv3cJ4FsawqwOoT341QQ30fHk0X2UDez4ooHzFJgzquapAhSMST/dAbT6o2cMrsqPm9xL3s0BaerfYttAzAmjxN8pjZTZ4Bi1eSs/28Ckooh99GEZd9ctCYafkGNO2LxgdONQpwrgcuxGpl/QoLpAYiZxdeNiSmbzGDPaOnR++4eBzlubu/Vnt6BiPh0nWs22OJSaaeqT/TnRQkNVa1D0eu6tydOmo+0XdVOidTxiDA=" Dec 30 06:20:19 volumio go-librespot[19271]: time="2025-12-30T06:20:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:19 volumio go-librespot[19271]: time="2025-12-30T06:20:19-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:19 volumio go-librespot[19271]: time="2025-12-30T06:20:19-06:00" level=debug msg="completed challenge" Dec 30 06:20:19 volumio go-librespot[19271]: time="2025-12-30T06:20: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 " Dec 30 06:20:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:19 volumio volumio[19108]: info: Loading plugin "youtube2"... Dec 30 06:20:20 volumio volumio[19108]: info: Loading plugin "ytcr"... Dec 30 06:20:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Dec 30 06:20:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:22 volumio go-librespot[19312]: go-librespot daemon starting... Dec 30 06:20:22 volumio go-librespot[19313]: time="2025-12-30T06:20:22-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:22 volumio go-librespot[19313]: time="2025-12-30T06:20:22-06:00" level=debug msg="app state loaded" Dec 30 06:20:22 volumio go-librespot[19313]: time="2025-12-30T06:20:22-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:22 volumio go-librespot[19313]: time="2025-12-30T06:20:22-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:22 volumio volumio[19108]: info: Loading plugin "ytmusic"... Dec 30 06:20:23 volumio go-librespot[19313]: time="2025-12-30T06:20: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:20:23 volumio go-librespot[19313]: time="2025-12-30T06:20:23-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]" Dec 30 06:20:23 volumio go-librespot[19313]: time="2025-12-30T06:20:23-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]" Dec 30 06:20:23 volumio go-librespot[19313]: time="2025-12-30T06:20:23-06:00" level=info msg="zeroconf server listening on port 34549" Dec 30 06:20:23 volumio go-librespot[19313]: time="2025-12-30T06:20:23-06:00" level=debug msg="obtained new client token: AACidjb2DGy16GwiuY2abO414I+vmVisWVB1s0DCd5esvKKvXpYdUotxcjRkWcp8uZt/ZQT1z9fkU8/RrcixjgVyP+HLqyzvZzcEVyfgo5SFOp0XfJUBgqMmZKyXGqfjhwgJ9uhHplZG3PNjQjdJ1G02GEFV0nnEAlC9P+12KuvPi/GbjpSDMrgITym8NzhzigAf80Xgo137RuO5m9Jt7IO74Ds2ZBK9listTckWV9T9UcAbprqtJJc=" Dec 30 06:20:23 volumio go-librespot[19313]: time="2025-12-30T06:20:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:23 volumio go-librespot[19313]: time="2025-12-30T06:20:23-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:23 volumio go-librespot[19313]: time="2025-12-30T06:20:23-06:00" level=debug msg="completed challenge" Dec 30 06:20:23 volumio go-librespot[19313]: time="2025-12-30T06:20: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 " Dec 30 06:20:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:23 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.72.90 Dec 30 06:20:23 volumio avahi-daemon[664]: Registering new address record for 169.254.72.90 on eth0.IPv4. Dec 30 06:20:23 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:20:23 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:23 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:23 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:23 volumio volumio[19108]: info: Plugin now_playing is not enabled Dec 30 06:20:23 volumio volumio[19108]: info: Loading plugin "outputs"... Dec 30 06:20:23 volumio volumio[19108]: info: Loading plugin "albumart"... Dec 30 06:20:23 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.72.90 Dec 30 06:20:23 volumio volumio[19108]: info: Plugin example_plugin is not enabled Dec 30 06:20:23 volumio volumio[19108]: info: Loading plugin "inputs"... Dec 30 06:20:23 volumio volumio[19108]: info: Loading plugin "updater_comm"... Dec 30 06:20:23 volumio volumio-remote-updater[702]: [2025-12-30 06:20:23] [connect] Successful connection Dec 30 06:20:23 volumio volumio[19108]: info: Plugin mpdemulation is not enabled Dec 30 06:20:23 volumio volumio[19108]: info: Loading plugin "rest_api"... Dec 30 06:20:23 volumio volumio[19108]: info: Loading plugin "websocket"... Dec 30 06:20:23 volumio volumio[19108]: info: Starting Socket.io Server version 1.7.4 Dec 30 06:20:23 volumio volumio[19108]: info: Plugin fusiondsp is not enabled Dec 30 06:20:23 volumio volumio[19108]: info: Plugin mpdoutput is not enabled Dec 30 06:20:23 volumio volumio[19108]: info: Plugin RoonBridge is not enabled Dec 30 06:20:23 volumio volumio[19108]: info: Loading plugin "podcast"... Dec 30 06:20:23 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.72.90 Dec 30 06:20:23 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.72.90 Dec 30 06:20:23 volumio avahi-daemon[664]: Withdrawing address record for 169.254.72.90 on eth0. Dec 30 06:20:23 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:24 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:24 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:24 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:24 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:24 volumio volumio[19108]: info: ControllerPodcast::constructor Dec 30 06:20:24 volumio volumio[19108]: info: Loading plugin "volusonic"... Dec 30 06:20:24 volumio volumio[19338]: Forking 3 albumart workers Dec 30 06:20:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Dec 30 06:20:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:26 volumio go-librespot[19394]: go-librespot daemon starting... Dec 30 06:20:26 volumio volumio[19366]: Starting albumart workers Dec 30 06:20:26 volumio go-librespot[19395]: time="2025-12-30T06:20:26-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:26 volumio go-librespot[19395]: time="2025-12-30T06:20:26-06:00" level=debug msg="app state loaded" Dec 30 06:20:26 volumio go-librespot[19395]: time="2025-12-30T06:20:26-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:26 volumio go-librespot[19395]: time="2025-12-30T06:20:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:26 volumio volumio[19108]: info: Applying required configuration parameters for plugin volusonic Dec 30 06:20:26 volumio volumio[19108]: info: Loading plugin "backup_restore"... Dec 30 06:20:26 volumio volumio[19364]: Starting albumart workers Dec 30 06:20:26 volumio volumio[19365]: Starting albumart workers Dec 30 06:20:27 volumio volumio[19108]: info: Applying required configuration parameters for plugin backup_restore Dec 30 06:20:27 volumio volumio[19108]: info: Plugin rpi_eeprom_config is not enabled Dec 30 06:20:27 volumio volumio[19108]: info: Plugin rpi_eeprom_updater is not enabled Dec 30 06:20:27 volumio volumio[19108]: info: Loading plugin "scheduledrestart"... Dec 30 06:20:27 volumio go-librespot[19395]: time="2025-12-30T06:20:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:20:27 volumio go-librespot[19395]: time="2025-12-30T06:20:27-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]" Dec 30 06:20:27 volumio go-librespot[19395]: time="2025-12-30T06:20:27-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]" Dec 30 06:20:27 volumio go-librespot[19395]: time="2025-12-30T06:20:27-06:00" level=info msg="zeroconf server listening on port 46801" Dec 30 06:20:27 volumio go-librespot[19395]: time="2025-12-30T06:20:27-06:00" level=debug msg="obtained new client token: AABQweO8mDurhVCl4cnjDKusSnBHke5EN3stTUQlcrFJlnDcS7FmH4oBuyZn4RD9nJTIbqGi5YFvk4UnPUCsb2K99JEj6PVLKkMP1QTjmPXhhFqtrNEQ4MI+DkUOOfXQNvu4Bgf7pGq6NfNAUp+J6sFxKAoytJ4v0O2UkzhVSex5HIbrLXKaNJZ66+V5j9qTrUfWCZLlt0AV1P4+1SyD+FOz51KNMwsW0SJ/np6jKWDlMz6Fi2wCSlnQ+g==" Dec 30 06:20:27 volumio go-librespot[19395]: time="2025-12-30T06:20:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:27 volumio volumio[19108]: info: Applying required configuration parameters for plugin scheduledrestart Dec 30 06:20:27 volumio volumio[19108]: info: Plugin Bluetoothremote is not enabled Dec 30 06:20:27 volumio volumio[19108]: info: Plugin music_services_shield is not enabled Dec 30 06:20:27 volumio volumio[19108]: info: Loading plugin "Systeminfo"... Dec 30 06:20:27 volumio go-librespot[19395]: time="2025-12-30T06:20:27-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:27 volumio go-librespot[19395]: time="2025-12-30T06:20:27-06:00" level=debug msg="completed challenge" Dec 30 06:20:27 volumio go-librespot[19395]: time="2025-12-30T06:20: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 " Dec 30 06:20:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:28 volumio volumio[19108]: info: Plugin peppymeterbasic is not enabled Dec 30 06:20:28 volumio volumio[19108]: info: Loading plugin "peppyspectrum"... Dec 30 06:20:28 volumio volumio[19108]: info: Loading i18n strings for locale en Dec 30 06:20:28 volumio volumio[19108]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 30 06:20:28 volumio volumio[19108]: Updating browse sources language Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::initPlayerControls Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 06:20:28 volumio volumio[19108]: Express server listening on port 3000 Dec 30 06:20:28 volumio volumio[19108]: [Metrics] WebUI: 20s 429.11ms Dec 30 06:20:28 volumio volumio[19108]: info: CoreStateMachine::resetVolumioState Dec 30 06:20:28 volumio volumio[19108]: info: CoreStateMachine::getcurrentVolume Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:28 volumio sudo[19425]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 06:20:28 volumio sudo[19425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:28 volumio sudo[19427]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 06:20:28 volumio sudo[19427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:28 volumio sudo[19425]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:28 volumio sudo[19427]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:28 volumio volumio[19108]: info: Volumio Network Manager: Network status updated: 1 Dec 30 06:20:28 volumio volumio[19108]: info: VolumeController:: Volume=100 Mute =false Dec 30 06:20:28 volumio volumio[19108]: info: CoreStateMachine::pushState Dec 30 06:20:28 volumio volumio[19108]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::volumioPushState Dec 30 06:20:28 volumio volumio[19108]: info: CoreStateMachine::updateTrackBlock Dec 30 06:20:28 volumio volumio[19108]: info: CorePlayQueue::getTrackBlock Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 06:20:28 volumio volumio[19108]: info: Reloading queue from file Dec 30 06:20:28 volumio volumio[19108]: info: CoreStateMachine::setRepeat null single undefined Dec 30 06:20:28 volumio volumio[19108]: info: CoreStateMachine::pushState Dec 30 06:20:28 volumio volumio[19108]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::volumioPushState Dec 30 06:20:28 volumio volumio[19108]: info: CoreStateMachine::setRandom null Dec 30 06:20:28 volumio volumio[19108]: info: CoreStateMachine::pushState Dec 30 06:20:28 volumio volumio[19108]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:28 volumio volumio[19108]: info: CoreCommandRouter::volumioPushState Dec 30 06:20:28 volumio volumio[19108]: info: Setting Device type: Raspberry PI Dec 30 06:20:29 volumio volumio[19108]: info: VolumeController:: Volume=100 Mute =false Dec 30 06:20:29 volumio volumio[19108]: info: CoreStateMachine::pushState Dec 30 06:20:29 volumio volumio[19108]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioPushState Dec 30 06:20:29 volumio volumio[19108]: info: Completed loading Core Plugins Dec 30 06:20:29 volumio volumio[19108]: info: Preparing to generate the ALSA configuration file Dec 30 06:20:29 volumio sudo[19441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 30 06:20:29 volumio sudo[19441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:29 volumio volumio[19108]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 30 06:20:29 volumio volumio[19108]: info: Discovery: Found device Volumio Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioGetState Dec 30 06:20:29 volumio volumio[19108]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:29 volumio volumio[19108]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 30 06:20:29 volumio volumio[19108]: info: Discovery: Found device Volumio Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioGetState Dec 30 06:20:29 volumio volumio[19108]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:29 volumio volumio[19108]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 06:20:29 volumio volumio[19108]: info: Reading ALSA contributions from plugins. Dec 30 06:20:29 volumio sudo[19441]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:29 volumio volumio[19108]: info: Upmpdcli Daemon Started Dec 30 06:20:29 volumio volumio[19108]: info: Asound.conf file unchanged, so no further update is needed Dec 30 06:20:29 volumio volumio[19108]: info: Output device has changed, restarting MPD Dec 30 06:20:29 volumio volumio[19108]: info: Output device has changed, restarting Shairport Sync Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:29 volumio sudo[19444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 06:20:29 volumio sudo[19444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:29 volumio sudo[19444]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:29 volumio sudo[19446]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 06:20:29 volumio sudo[19446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:29 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.44.247 Dec 30 06:20:29 volumio avahi-daemon[664]: Registering new address record for 169.254.44.247 on eth0.IPv4. Dec 30 06:20:29 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:20:29 volumio volumio[19108]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 06:20:29 volumio volumio[19108]: info: ___________ START PLUGINS ___________ Dec 30 06:20:29 volumio volumio[19108]: info: ControllerMpd::onStart: Initializing MPD Dec 30 06:20:29 volumio volumio[19108]: info: Creating MPD Configuration file Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:29 volumio volumio[19108]: info: [1767097229231] CoreMusicLibrary::Adding element Media Servers Dec 30 06:20:29 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:29 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:29 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:29 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 30 06:20:29 volumio sudo[19469]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 06:20:29 volumio sudo[19469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:29 volumio sudo[19469]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:29 volumio sudo[19472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 06:20:29 volumio sudo[19472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:29 volumio volumio[19108]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:29 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 30 06:20:29 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 06:20:29 volumio systemd[1]: mpd.service: Consumed 5.796s CPU time. Dec 30 06:20:29 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 30 06:20:29 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 06:20:29 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 06:20:29 volumio volumio[19108]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:29 volumio volumio[19108]: info: [1767097229362] CoreMusicLibrary::Adding element Last_100 Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:29 volumio volumio[19108]: info: [1767097229365] CoreMusicLibrary::Adding element Webradio Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 06:20:29 volumio volumio[19108]: info: Initializing BBC Radios Dec 30 06:20:29 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 06:20:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:29 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.44.247 Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:29 volumio volumio[19108]: info: [1767097229444] CoreMusicLibrary::Adding element Bandcamp Discover Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:29 volumio volumio[19108]: info: [1767097229455] CoreMusicLibrary::Adding element SoundCloud Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source SoundCloud Dec 30 06:20:29 volumio volumio[19108]: info: Creating Spotify config file Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:29 volumio sudo[19496]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 06:20:29 volumio sudo[19496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 06:20:29 volumio sudo[19496]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:29 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.44.247 Dec 30 06:20:29 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.44.247 Dec 30 06:20:29 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:29 volumio avahi-daemon[664]: Withdrawing address record for 169.254.44.247 on eth0. Dec 30 06:20:29 volumio volumio[19108]: info: [squeezelite_mc] Starting proxy server... Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:29 volumio volumio[19108]: info: [1767097229825] CoreMusicLibrary::Adding element YouTube2 Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source SoundCloud Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube2 Dec 30 06:20:29 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:29 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:29 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:29 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:29 volumio volumio[19108]: info: [1767097229860] CoreMusicLibrary::Adding element YouTube Music Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source SoundCloud Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube2 Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube Music Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:29 volumio volumio[19108]: info: [1767097229872] CoreMusicLibrary::Adding element Podcast Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source SoundCloud Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube2 Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube Music Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Podcast Dec 30 06:20:29 volumio volumio[19108]: info: Loading i18n strings for locale en Dec 30 06:20:29 volumio volumio[19108]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 30 06:20:29 volumio volumio[19108]: Updating browse sources language Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source SoundCloud Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube2 Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube Music Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Podcast Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source SoundCloud Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube2 Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube Music Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Podcast Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:29 volumio volumio[19108]: info: [1767097229926] CoreMusicLibrary::Adding element Volusonic Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source SoundCloud Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube2 Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source YouTube Music Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Podcast Dec 30 06:20:29 volumio volumio[19108]: Cannot find translation for source Volusonic Dec 30 06:20:29 volumio volumio[19108]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 30 06:20:29 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 30 06:20:29 volumio volumio[19108]: info: Volumio Calling Home Dec 30 06:20:30 volumio volumio[19108]: info: [squeezelite_mc] Proxy server started on port 39315 Dec 30 06:20:30 volumio volumio[19108]: info: Preparing to generate the ALSA configuration file Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 06:20:30 volumio volumio[19108]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 06:20:30 volumio volumio[19108]: info: Reading ALSA contributions from plugins. Dec 30 06:20:30 volumio volumio[19108]: info: MPD Permissions set Dec 30 06:20:30 volumio volumio[19108]: info: MPD Permissions set Dec 30 06:20:30 volumio volumio[19108]: info: Spotify config file written Dec 30 06:20:30 volumio sudo[19523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 06:20:30 volumio sudo[19523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:30 volumio volumio[19108]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Dec 30 06:20:30 volumio volumio[19108]: info: VolumeController:: Volume=100 Mute =false Dec 30 06:20:30 volumio volumio[19108]: info: CoreStateMachine::pushState Dec 30 06:20:30 volumio volumio[19108]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::volumioPushState Dec 30 06:20:30 volumio volumio[19108]: info: [squeezelite_mc] Server discovery started Dec 30 06:20:30 volumio volumio[19108]: info: [squeezelite_mc] Player finder started Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 30 06:20:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:30 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:30 volumio go-librespot[19527]: go-librespot daemon starting... Dec 30 06:20:30 volumio volumio[19108]: info: No need to fix Spotify hosts Dec 30 06:20:30 volumio go-librespot[19538]: time="2025-12-30T06:20:30-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:30 volumio go-librespot[19538]: time="2025-12-30T06:20:30-06:00" level=debug msg="app state loaded" Dec 30 06:20:30 volumio go-librespot[19538]: time="2025-12-30T06:20:30-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:30 volumio go-librespot[19538]: time="2025-12-30T06:20:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:30 volumio sudo[19523]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:30 volumio volumio[19108]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 30 06:20:30 volumio volumio[19108]: info: Volumio called home Dec 30 06:20:30 volumio kernel: hwmon hwmon1: Voltage normalised Dec 30 06:20:30 volumio volumio[19108]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 30 06:20:30 volumio volumio[19108]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 30 06:20:30 volumio volumio[19108]: 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 Dec 30 06:20:30 volumio volumio[19108]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 06:20:30 volumio volumio[19108]: SPOTIFY: BQBMswaSUlIP9SP37YQk8ucRU6O4n4mQw6FRLqRzv7btZ447kcqII_Z2c1Es3TjFfEUrGyYpTSqihuByqKIKY4ffxODs9qwJqRuDpuCp4RZECyp2vRkDjYjLcJQ5oI2-pj0Fz3Ze_FAgjGivusmhTNUhz6aLKT1vth4XsQW7M9g-ZD4W4iLO26NhKBiIELO77dQzCF4LZECC5_RcmIGfZLzlocucCHeF7gryz3Q Dec 30 06:20:30 volumio volumio[19108]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 06:20:30 volumio volumio[19108]: info: New Spotify access token = BQBMswaSUlIP9SP37YQk8ucRU6O4n4mQw6FRLqRzv7btZ447kcqII_Z2c1Es3TjFfEUrGyYpTSqihuByqKIKY4ffxODs9qwJqRuDpuCp4RZECyp2vRkDjYjLcJQ5oI2-pj0Fz3Ze_FAgjGivusmhTNUhz6aLKT1vth4XsQW7M9g-ZD4W4iLO26NhKBiIELO77dQzCF4LZECC5_RcmIGfZLzlocucCHeF7gryz3Q Dec 30 06:20:30 volumio volumio[19108]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 30 06:20:30 volumio go-librespot[19538]: time="2025-12-30T06:20: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:20:30 volumio go-librespot[19538]: time="2025-12-30T06:20:30-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]" Dec 30 06:20:30 volumio go-librespot[19538]: time="2025-12-30T06:20:30-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]" Dec 30 06:20:30 volumio sudo[19549]: 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 Dec 30 06:20:30 volumio sudo[19549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:30 volumio go-librespot[19538]: time="2025-12-30T06:20:30-06:00" level=info msg="zeroconf server listening on port 38837" Dec 30 06:20:30 volumio sudo[19549]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:30 volumio volumio[19108]: info: Starting Shairport Sync Dec 30 06:20:30 volumio volumio[19108]: info: Starting Shairport Sync Dec 30 06:20:30 volumio volumio[19108]: info: Starting Shairport Sync Dec 30 06:20:30 volumio sudo[19556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 06:20:30 volumio volumio[19108]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 30 06:20:30 volumio go-librespot[19538]: time="2025-12-30T06:20:30-06:00" level=debug msg="obtained new client token: AABp/iT1wgXqjmVHRti3zBMCu2p6yIS2gAenKy2xZKgOGlr1vCjkE7Sz8ImyAWGRGDUvrXoywFtuqdvoyFMvNyp/3+gE4hFex0EJSdXx3wJc/+zoPpj1DQBSXA1nPqw5YAaC1XXRRRJWGPnJ4Mit6qUkw9JnRswFL8idCah+Autf2G7nov5l2NtA7W5qh4bWbZgZPip6dovbE6ds3J2RCRZ8xa0lHRhAntdQHYv5tlOtC+MQ6qKAD5uM8Q==" Dec 30 06:20:30 volumio sudo[19554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 06:20:30 volumio sudo[19554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:30 volumio sudo[19552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 06:20:30 volumio sudo[19552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:30 volumio sudo[19556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:30 volumio go-librespot[19538]: time="2025-12-30T06:20:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:30 volumio sudo[19566]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 30 06:20:31 volumio sudo[19566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:31 volumio go-librespot[19538]: time="2025-12-30T06:20:31-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:31 volumio go-librespot[19538]: time="2025-12-30T06:20:31-06:00" level=debug msg="completed challenge" Dec 30 06:20:31 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 06:20:31 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 06:20:31 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 06:20:31 volumio systemd[1]: shairport-sync.service: Consumed 2.147s CPU time. Dec 30 06:20:31 volumio sudo[19566]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:31 volumio volumio[19108]: info: Asound.conf file unchanged, so no further update is needed Dec 30 06:20:31 volumio volumio[19108]: info: Output device has changed, restarting MPD Dec 30 06:20:31 volumio go-librespot[19538]: time="2025-12-30T06:20: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 " Dec 30 06:20:31 volumio volumio[19108]: info: Output device has changed, restarting Shairport Sync Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:31 volumio sudo[19581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 06:20:31 volumio sudo[19581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:31 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 06:20:31 volumio sudo[19552]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:31 volumio sudo[19583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 06:20:31 volumio sudo[19583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:31 volumio sudo[19554]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:31 volumio sudo[19556]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:31 volumio sudo[19581]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:31 volumio volumio[19108]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 06:20:31 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 30 06:20:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 06:20:31 volumio systemd[1]: mpd.service: Consumed 1.676s CPU time. Dec 30 06:20:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 30 06:20:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 06:20:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 06:20:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 06:20:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 06:20:31 volumio volumio[19108]: info: MPD Permissions set Dec 30 06:20:31 volumio volumio[19108]: info: Shairport-Sync Started Dec 30 06:20:31 volumio volumio[19108]: Error adding Membership: Error: addMembership EINVAL Dec 30 06:20:31 volumio volumio[19108]: info: Shairport-Sync Started Dec 30 06:20:31 volumio volumio[19108]: info: Shairport-Sync Started Dec 30 06:20:31 volumio volumio[19108]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 30 06:20:31 volumio sudo[19611]: 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 Dec 30 06:20:31 volumio sudo[19611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:31 volumio sudo[19611]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:31 volumio volumio[19108]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:31 volumio sudo[19614]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 30 06:20:31 volumio sudo[19614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:31 volumio sudo[19608]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 06:20:31 volumio sudo[19608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 06:20:31 volumio sudo[19608]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:31 volumio volumio[19108]: info: CoreCommandRouter::volumioGetState Dec 30 06:20:31 volumio volumio[19108]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:32 volumio volumio[19108]: info: Starting Shairport Sync Dec 30 06:20:32 volumio volumio[19108]: 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"} Dec 30 06:20:32 volumio volumio[19108]: info: Spotify Successfully logged in Dec 30 06:20:32 volumio systemd[1]: Reloading. Dec 30 06:20:32 volumio volumio[19108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:32 volumio volumio[19108]: info: [1767097232100] CoreMusicLibrary::Adding element Spotify Dec 30 06:20:32 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:32 volumio volumio[19108]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:32 volumio volumio[19108]: Cannot find translation for source SoundCloud Dec 30 06:20:32 volumio volumio[19108]: Cannot find translation for source YouTube2 Dec 30 06:20:32 volumio volumio[19108]: Cannot find translation for source YouTube Music Dec 30 06:20:32 volumio volumio[19108]: Cannot find translation for source Podcast Dec 30 06:20:32 volumio volumio[19108]: Cannot find translation for source Volusonic Dec 30 06:20:32 volumio volumio[19108]: Cannot find translation for source Spotify Dec 30 06:20:32 volumio sudo[19624]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 06:20:32 volumio sudo[19624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:32 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:32 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:32 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:32 volumio volumio[19108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 06:20:32 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 06:20:33 volumio volumio[19108]: info: go-librespot daemon successfully initialized Dec 30 06:20:34 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. Dec 30 06:20:34 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. Dec 30 06:20:34 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.247.60 Dec 30 06:20:34 volumio avahi-daemon[664]: Registering new address record for 169.254.247.60 on eth0.IPv4. Dec 30 06:20:34 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:20:35 volumio volumio[19108]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 06:20:35 volumio sudo[19614]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Dec 30 06:20:35 volumio volumio[19108]: Error: addMembership ENODEV Dec 30 06:20:35 volumio volumio[19108]: at Socket.addMembership (node:dgram:860:11) Dec 30 06:20:35 volumio volumio[19108]: at addMembership (/volumio/node_modules/node-ssdp/lib/index.js:264:16) { Dec 30 06:20:35 volumio volumio[19108]: errno: -19, Dec 30 06:20:35 volumio volumio[19108]: code: 'ENODEV', Dec 30 06:20:35 volumio volumio[19108]: syscall: 'addMembership' Dec 30 06:20:35 volumio volumio[19108]: } Dec 30 06:20:35 volumio volumio[19108]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 06:20:35 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.247.60 Dec 30 06:20:35 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:35 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:35 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:35 volumio go-librespot[19670]: go-librespot daemon starting... Dec 30 06:20:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 06:20:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 06:20:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 06:20:35 volumio systemd[1]: shairport-sync.service: Consumed 1.527s CPU time. Dec 30 06:20:35 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.247.60 Dec 30 06:20:35 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.247.60 Dec 30 06:20:35 volumio avahi-daemon[664]: Withdrawing address record for 169.254.247.60 on eth0. Dec 30 06:20:35 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 06:20:35 volumio sudo[19624]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=debug msg="app state loaded" Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:35 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:35 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:35 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:35 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-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]" Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-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]" Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=info msg="zeroconf server listening on port 35413" Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=debug msg="obtained new client token: AADSsyIC0urarB/62XUDFcme1ZuH4rBKzgftXcKkc6d4QvwutFFsxbykCoQHjlh70OfPnTcXbBImQp4zWeIlLrnFKu9kBxOwkg0cjm+OJYr8sc1Tx/rbBLX4YvVOXDaCUtI/6nt6DNMT2TNmawTEI3BxJzLfAN9yNsP0DjOqyxM3PGM88I0gI72o7db9Ek0IyH84ti3/7FjqIKyOtdkafkR794nVkzdAteGmbJe9UpSBmuHSYsz41vFp7Q==" Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=debug msg="completed challenge" Dec 30 06:20:35 volumio go-librespot[19672]: time="2025-12-30T06:20:35-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 06:20:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:36 volumio sudo[19712]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-30 06:19' Dec 30 06:20:36 volumio sudo[19712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:36 volumio sudo[19712]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:36 volumio mpd[19622]: 2025-12-30T06:20:36 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 30 06:20:36 volumio kernel: hwmon hwmon1: Voltage normalised Dec 30 06:20:36 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 30 06:20:36 volumio sudo[19583]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:36 volumio sudo[19472]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:36 volumio sudo[19446]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:37 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:37 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 30 06:20:37 volumio systemd[1]: volumio.service: Consumed 45.548s CPU time. Dec 30 06:20:37 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 30 06:20:37 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 30 06:20:37 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 398. Dec 30 06:20:37 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 30 06:20:37 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 30 06:20:37 volumio systemd[1]: volumio.service: Consumed 45.548s CPU time. Dec 30 06:20:37 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Dec 30 06:20:37 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Dec 30 06:20:38 volumio volumio-remote-updater[702]: [2025-12-30 06:20:38] [info] asio async_connect error: asio.system:111 (Connection refused) Dec 30 06:20:38 volumio volumio-remote-updater[702]: [2025-12-30 06:20:38] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Dec 30 06:20:38 volumio volumio-remote-updater[702]: [2025-12-30 06:20:38] [error] handle_connect error: Connection refused Dec 30 06:20:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Dec 30 06:20:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:39 volumio go-librespot[19745]: go-librespot daemon starting... Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-06:00" level=debug msg="app state loaded" Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-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]" Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-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]" Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-06:00" level=info msg="zeroconf server listening on port 34575" Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-06:00" level=debug msg="obtained new client token: AAD0Z6H04mrzW5/WWXALTuevj3mZqo7CMCjYClryk/NZdVO7y/Gu9SkmKyBhSt2IT+3/8rNJHPqfhKxMt7jf5VsyJpepsukrxJcOJR7S6Rtk3vk0WP09o5pe4cxbHH2BhDqx2pzqI8le1Kjnpak4/zSI5JPjanAJ/4K4E1B2R5t2Aa9Mo87SAJD0olu1+tgTK3MefomBus7b3BtifuaqvNaDF1vd9TVX6vAq/FW/hbiaq2ir+Izz13PqXg==" Dec 30 06:20:39 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.143.5 Dec 30 06:20:39 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:20:39 volumio avahi-daemon[664]: Registering new address record for 169.254.143.5 on eth0.IPv4. Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:39 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:39 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:39 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:39 volumio volumio[19730]: info: ------------------------------------------- Dec 30 06:20:39 volumio volumio[19730]: info: ----- Volumio3 ---- Dec 30 06:20:39 volumio volumio[19730]: info: ------------------------------------------- Dec 30 06:20:39 volumio volumio[19730]: info: ----- System startup ---- Dec 30 06:20:39 volumio volumio[19730]: info: ------------------------------------------- Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-06:00" level=debug msg="completed challenge" Dec 30 06:20:39 volumio go-librespot[19746]: time="2025-12-30T06:20:39-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 " Dec 30 06:20:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:40 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.143.5 Dec 30 06:20:40 volumio volumio[19730]: info: MYVOLUMIO Environment detected Dec 30 06:20:40 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.143.5 Dec 30 06:20:40 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.143.5 Dec 30 06:20:40 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:40 volumio avahi-daemon[664]: Withdrawing address record for 169.254.143.5 on eth0. Dec 30 06:20:40 volumio volumio[19730]: info: Plugin folders cleanup Dec 30 06:20:40 volumio volumio[19730]: info: Scanning into folder /volumio/app/plugins/ Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category audio_interface Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category miscellanea Dec 30 06:20:40 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:40 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:40 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category music_service Dec 30 06:20:40 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category plugins.json Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category system_controller Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category user_interface Dec 30 06:20:40 volumio volumio[19730]: info: Scanning into folder /data/plugins/ Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category audio_interface Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category music_service Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category system_controller Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category system_hardware Dec 30 06:20:40 volumio volumio[19730]: info: Scanning category user_interface Dec 30 06:20:40 volumio volumio[19730]: info: Plugin folders cleanup completed Dec 30 06:20:40 volumio volumio[19730]: info: ------------------------------------------- Dec 30 06:20:40 volumio volumio[19730]: info: ----- Core plugins startup ---- Dec 30 06:20:40 volumio volumio[19730]: info: ------------------------------------------- Dec 30 06:20:40 volumio volumio[19730]: info: Loading plugins from folder /volumio/app/plugins/ Dec 30 06:20:40 volumio volumio[19730]: info: Adding plugin upnp to MyMusic Plugins Dec 30 06:20:40 volumio volumio[19730]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 30 06:20:40 volumio volumio[19730]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 30 06:20:40 volumio volumio[19730]: info: Loading plugins from folder /data/plugins/ Dec 30 06:20:40 volumio volumio[19730]: info: Loading plugin "system"... Dec 30 06:20:40 volumio volumio[19730]: info: Loading plugin "appearance"... Dec 30 06:20:41 volumio volumio[19730]: info: Loading plugin "network"... Dec 30 06:20:41 volumio volumio[19730]: info: Refreshing Cached IP Addresses Dec 30 06:20:41 volumio sudo[19802]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 06:20:41 volumio sudo[19802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:41 volumio sudo[19804]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 06:20:41 volumio sudo[19804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:41 volumio sudo[19802]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:41 volumio volumio[19730]: info: Loading plugin "services"... Dec 30 06:20:41 volumio volumio[19730]: info: Loading plugin "alsa_controller"... Dec 30 06:20:41 volumio sudo[19804]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:41 volumio sudo[19813]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 30 06:20:41 volumio sudo[19813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:41 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 06:20:41 volumio volumio[19730]: info: Loading plugin "wizard"... Dec 30 06:20:41 volumio volumio[19730]: info: Loading plugin "networkfs"... Dec 30 06:20:41 volumio volumio[19730]: info: Starting Udev Watcher for removable devices Dec 30 06:20:42 volumio volumio[19730]: info: Ignoring mount for partition: boot Dec 30 06:20:42 volumio volumio[19730]: info: Ignoring mount for partition: volumio Dec 30 06:20:42 volumio volumio[19730]: info: Ignoring mount for partition: volumio_data Dec 30 06:20:42 volumio volumio[19730]: info: Mounting Device Wikipedia Dec 30 06:20:42 volumio sudo[19842]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Dec 30 06:20:42 volumio sudo[19842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:42 volumio sudo[19842]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:42 volumio volumio[19730]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 30 06:20:42 volumio volumio[19730]: dmesg(1) may have more information after failed mount system call. Dec 30 06:20:42 volumio volumio[19730]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Dec 30 06:20:42 volumio volumio[19730]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Dec 30 06:20:42 volumio volumio[19730]: dmesg(1) may have more information after failed mount system call. Dec 30 06:20:42 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 06:20:42 volumio volumio[19730]: info: Loading plugin "volumio_command_line_client"... Dec 30 06:20:42 volumio volumio[19730]: info: Loading plugin "upnp"... Dec 30 06:20:42 volumio volumio[19730]: info: [1767097242195] Starting Upmpd Daemon Dec 30 06:20:42 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 06:20:42 volumio volumio[19730]: info: Loading plugin "my_music"... Dec 30 06:20:42 volumio volumio[19730]: info: Loading plugin "mpd"... Dec 30 06:20:42 volumio sudo[19813]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:42 volumio volumio[19730]: info: Loading plugin "upnp_browser"... Dec 30 06:20:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Dec 30 06:20:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:43 volumio go-librespot[19844]: go-librespot daemon starting... Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-06:00" level=debug msg="app state loaded" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:43 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20: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-gew1.spotify.com:80]" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-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]" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-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]" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-06:00" level=info msg="zeroconf server listening on port 45411" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-06:00" level=debug msg="obtained new client token: AACKAIhHuFtd0bF1EI+aY9dGN/3CfIL5MYClr4gWJo8jH15XDq1ls1A18qOfE3eICRcozHG8cUZY/so8HCM/Ip9AJ54op/Meanw3oUxIdypp9d2h1Pj8QanIVbS7+eVEI3kiQd7F0jP9WAQlMyJL3l1/gyyOCY2eCnSt0GldwCESOKsxsLRCkJznZPxgdSzqJgAyHZfrkDAgUfrF5wsKn2zQ4L+5ZJMm7izlOcST6akErFIenpji68fPMw==" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20:43-06:00" level=debug msg="completed challenge" Dec 30 06:20:43 volumio go-librespot[19845]: time="2025-12-30T06:20: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 " Dec 30 06:20:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:45 volumio volumio[19730]: info: Loading plugin "alarm-clock"... Dec 30 06:20:45 volumio volumio[19730]: info: Loading plugin "airplay_emulation"... Dec 30 06:20:45 volumio volumio[19730]: info: Starting Shairport Sync Dec 30 06:20:45 volumio volumio[19730]: info: Loading plugin "last_100"... Dec 30 06:20:45 volumio volumio[19730]: info: Loading plugin "webradio"... Dec 30 06:20:45 volumio volumio[19730]: info: Loading plugin "i2s_dacs"... Dec 30 06:20:45 volumio volumio[19730]: info: I2S DAC not set, start Auto-detection Dec 30 06:20:45 volumio volumio[19730]: info: Loading plugin "volumiodiscovery"... Dec 30 06:20:45 volumio volumio[19730]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 30 06:20:45 volumio volumio[19730]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 06:20:45 volumio volumio[19730]: *** WARNING *** For more information see Dec 30 06:20:45 volumio volumio[19730]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 30 06:20:45 volumio volumio[19730]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 06:20:45 volumio volumio[19730]: *** WARNING *** For more information see Dec 30 06:20:45 volumio node[19730]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 30 06:20:45 volumio node[19730]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 06:20:45 volumio node[19730]: *** WARNING *** For more information see Dec 30 06:20:45 volumio node[19730]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 30 06:20:45 volumio node[19730]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 06:20:45 volumio node[19730]: *** WARNING *** For more information see Dec 30 06:20:45 volumio volumio[19730]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 30 06:20:45 volumio volumio[19730]: info: Discovery: Started advertising with name: Volumio Dec 30 06:20:45 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 06:20:45 volumio volumio[19730]: info: Loading plugin "bandcamp"... Dec 30 06:20:46 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.201.205 Dec 30 06:20:46 volumio avahi-daemon[664]: Registering new address record for 169.254.201.205 on eth0.IPv4. Dec 30 06:20:46 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:20:46 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:46 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:46 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:46 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.201.205 Dec 30 06:20:46 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.201.205 Dec 30 06:20:46 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.201.205 Dec 30 06:20:46 volumio avahi-daemon[664]: Withdrawing address record for 169.254.201.205 on eth0. Dec 30 06:20:46 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Dec 30 06:20:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:46 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:46 volumio go-librespot[19887]: go-librespot daemon starting... Dec 30 06:20:46 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:46 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:46 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-06:00" level=debug msg="app state loaded" Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:47 volumio volumio[19730]: info: Plugin calmradio is not enabled Dec 30 06:20:47 volumio volumio[19730]: info: Loading plugin "soundcloud"... Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-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]" Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-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]" Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-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]" Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-06:00" level=info msg="zeroconf server listening on port 42641" Dec 30 06:20:47 volumio kernel: hwmon hwmon1: Voltage normalised Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-06:00" level=debug msg="obtained new client token: AABG6tb3B5YQ8imLMG8JCBkR8lpbBgd+NRGxsrETz5sbOW2K18bTnXqibRyL3lzQuU3hHcGbtHs2AEUcinGf5o3Q3Q+Y8jOvYDN8bOVXlbee15s4VpX8mJNF1RGE/a9FfGVf0VnpplaKVTONtxL2SD9g3IbbGd0nr4OlUtXOsSsQUW+MMQSXBJQQF3+w5lebP0ad67MzfZ2JgEXgRpkHp4yj6YBYvl/UW6Khs7uCsexy/4DumERxg4sdfA==" Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-06:00" level=debug msg="completed challenge" Dec 30 06:20:47 volumio go-librespot[19888]: time="2025-12-30T06:20:47-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 " Dec 30 06:20:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:47 volumio volumio[19730]: info: Loading plugin "spop"... Dec 30 06:20:48 volumio volumio[19730]: info: Loading plugin "squeezelite_mc"... Dec 30 06:20:48 volumio volumio-remote-updater[702]: [2025-12-30 06:20:48] [connect] Successful connection Dec 30 06:20:49 volumio volumio[19730]: info: Loading plugin "youtube2"... Dec 30 06:20:50 volumio volumio[19730]: info: Loading plugin "ytcr"... Dec 30 06:20:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Dec 30 06:20:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:50 volumio go-librespot[19896]: go-librespot daemon starting... Dec 30 06:20:50 volumio go-librespot[19897]: time="2025-12-30T06:20:50-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:50 volumio go-librespot[19897]: time="2025-12-30T06:20:50-06:00" level=debug msg="app state loaded" Dec 30 06:20:50 volumio go-librespot[19897]: time="2025-12-30T06:20:50-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:50 volumio go-librespot[19897]: time="2025-12-30T06:20:50-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:51 volumio go-librespot[19897]: time="2025-12-30T06:20: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:20:51 volumio go-librespot[19897]: time="2025-12-30T06:20:51-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]" Dec 30 06:20:51 volumio go-librespot[19897]: time="2025-12-30T06:20:51-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]" Dec 30 06:20:51 volumio go-librespot[19897]: time="2025-12-30T06:20:51-06:00" level=info msg="zeroconf server listening on port 35223" Dec 30 06:20:51 volumio go-librespot[19897]: time="2025-12-30T06:20:51-06:00" level=debug msg="obtained new client token: AAA+0r4O1/hatwvmCvb2WVwXjxULkeZD9UDfzPg4jHvElujp3x2voD2fY+JC6rNb2bdcmuMKSmigP+uDqcXY1R+aAGyXltj30SGIY4oqToXc7DznK4cfdB4T+lyb1sNoBvh1oBgDLr79lzyJzkrRl5wL32tv1aCX/2gEfs94HeZ5xCQ95xmYpr6ELNgFj1jCrIn7NOhBg4jjjGhdB2rNEp4N7D19VmD6oqt3cOCYhXldH4m64N5Tys2Onw==" Dec 30 06:20:51 volumio go-librespot[19897]: time="2025-12-30T06:20:51-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:51 volumio go-librespot[19897]: time="2025-12-30T06:20:51-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:51 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 06:20:51 volumio go-librespot[19897]: time="2025-12-30T06:20:51-06:00" level=debug msg="completed challenge" Dec 30 06:20:51 volumio go-librespot[19897]: time="2025-12-30T06:20:51-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 " Dec 30 06:20:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:51 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.194.240 Dec 30 06:20:51 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:20:51 volumio avahi-daemon[664]: Registering new address record for 169.254.194.240 on eth0.IPv4. Dec 30 06:20:51 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:51 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:51 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:52 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.194.240 Dec 30 06:20:52 volumio volumio[19730]: info: Loading plugin "ytmusic"... Dec 30 06:20:52 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.194.240 Dec 30 06:20:52 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.194.240 Dec 30 06:20:52 volumio avahi-daemon[664]: Withdrawing address record for 169.254.194.240 on eth0. Dec 30 06:20:52 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:52 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:52 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:52 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:52 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:53 volumio volumio[19730]: info: Plugin now_playing is not enabled Dec 30 06:20:53 volumio volumio[19730]: info: Loading plugin "outputs"... Dec 30 06:20:53 volumio volumio[19730]: info: Loading plugin "albumart"... Dec 30 06:20:53 volumio volumio[19730]: info: Plugin example_plugin is not enabled Dec 30 06:20:53 volumio volumio[19730]: info: Loading plugin "inputs"... Dec 30 06:20:53 volumio volumio[19730]: info: Loading plugin "updater_comm"... Dec 30 06:20:53 volumio volumio[19730]: info: Plugin mpdemulation is not enabled Dec 30 06:20:53 volumio volumio[19730]: info: Loading plugin "rest_api"... Dec 30 06:20:53 volumio volumio[19730]: info: Loading plugin "websocket"... Dec 30 06:20:53 volumio volumio[19730]: info: Starting Socket.io Server version 1.7.4 Dec 30 06:20:53 volumio volumio[19730]: info: Plugin fusiondsp is not enabled Dec 30 06:20:53 volumio volumio[19730]: info: Plugin mpdoutput is not enabled Dec 30 06:20:53 volumio volumio[19730]: info: Plugin RoonBridge is not enabled Dec 30 06:20:53 volumio volumio[19730]: info: Loading plugin "podcast"... Dec 30 06:20:53 volumio volumio[19730]: info: ControllerPodcast::constructor Dec 30 06:20:53 volumio volumio[19730]: info: Loading plugin "volusonic"... Dec 30 06:20:53 volumio volumio[19951]: Forking 3 albumart workers Dec 30 06:20:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Dec 30 06:20:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:54 volumio go-librespot[19991]: go-librespot daemon starting... Dec 30 06:20:54 volumio go-librespot[19992]: time="2025-12-30T06:20:54-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:54 volumio go-librespot[19992]: time="2025-12-30T06:20:54-06:00" level=debug msg="app state loaded" Dec 30 06:20:54 volumio go-librespot[19992]: time="2025-12-30T06:20:54-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:54 volumio go-librespot[19992]: time="2025-12-30T06:20:54-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:55 volumio go-librespot[19992]: time="2025-12-30T06:20: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:20:55 volumio go-librespot[19992]: time="2025-12-30T06:20:55-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]" Dec 30 06:20:55 volumio go-librespot[19992]: time="2025-12-30T06:20:55-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]" Dec 30 06:20:55 volumio go-librespot[19992]: time="2025-12-30T06:20:55-06:00" level=info msg="zeroconf server listening on port 34245" Dec 30 06:20:55 volumio go-librespot[19992]: time="2025-12-30T06:20:55-06:00" level=debug msg="obtained new client token: AAAl4qNNKQWxKgo/61YBmNUJwX8R3DC+q5BeNrkxg/M8gbrVdN59tIecDGEMUDMJYWxicM4emgGr1bFv4bPkeyM2mbxnSD4gFFuOsCTAEn3xM5eOSEcEAxVOqqMBvgMqUVAa9V55wai4uQiHnF59wu3tBpP9EI81H1OqZVUR4soTZ1i1rXReXKuIphpcurYbhXcizDbno87taGla7OSUXp47FUE38qPuSa82jY7wwDIRxlbq+anQsgBp8w==" Dec 30 06:20:55 volumio go-librespot[19992]: time="2025-12-30T06:20:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:55 volumio go-librespot[19992]: time="2025-12-30T06:20:55-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:55 volumio go-librespot[19992]: time="2025-12-30T06:20:55-06:00" level=debug msg="completed challenge" Dec 30 06:20:55 volumio go-librespot[19992]: time="2025-12-30T06:20:55-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 " Dec 30 06:20:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:56 volumio volumio[19963]: Starting albumart workers Dec 30 06:20:56 volumio volumio[19730]: info: Applying required configuration parameters for plugin volusonic Dec 30 06:20:56 volumio volumio[19730]: info: Loading plugin "backup_restore"... Dec 30 06:20:56 volumio volumio[19961]: Starting albumart workers Dec 30 06:20:56 volumio volumio[19962]: Starting albumart workers Dec 30 06:20:57 volumio volumio[19730]: info: Applying required configuration parameters for plugin backup_restore Dec 30 06:20:57 volumio volumio[19730]: info: Plugin rpi_eeprom_config is not enabled Dec 30 06:20:57 volumio volumio[19730]: info: Plugin rpi_eeprom_updater is not enabled Dec 30 06:20:57 volumio volumio[19730]: info: Loading plugin "scheduledrestart"... Dec 30 06:20:57 volumio volumio[19730]: info: Applying required configuration parameters for plugin scheduledrestart Dec 30 06:20:57 volumio volumio[19730]: info: Plugin Bluetoothremote is not enabled Dec 30 06:20:57 volumio volumio[19730]: info: Plugin music_services_shield is not enabled Dec 30 06:20:57 volumio volumio[19730]: info: Loading plugin "Systeminfo"... Dec 30 06:20:57 volumio volumio[19730]: info: Plugin peppymeterbasic is not enabled Dec 30 06:20:57 volumio volumio[19730]: info: Loading plugin "peppyspectrum"... Dec 30 06:20:57 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.213.79 Dec 30 06:20:57 volumio avahi-daemon[664]: Registering new address record for 169.254.213.79 on eth0.IPv4. Dec 30 06:20:57 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:20:57 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:57 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:57 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:57 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.213.79 Dec 30 06:20:58 volumio volumio[19730]: info: Loading i18n strings for locale en Dec 30 06:20:58 volumio volumio[19730]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 30 06:20:58 volumio volumio[19730]: Updating browse sources language Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::initPlayerControls Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: Express server listening on port 3000 Dec 30 06:20:58 volumio volumio[19730]: [Metrics] WebUI: 19s 192.85ms Dec 30 06:20:58 volumio volumio[19730]: info: CoreStateMachine::resetVolumioState Dec 30 06:20:58 volumio volumio[19730]: info: CoreStateMachine::getcurrentVolume Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:58 volumio sudo[20038]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 06:20:58 volumio sudo[20038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:58 volumio sudo[20038]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:58 volumio sudo[20040]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 06:20:58 volumio sudo[20040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:58 volumio sudo[20040]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:58 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.213.79 Dec 30 06:20:58 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.213.79 Dec 30 06:20:58 volumio avahi-daemon[664]: Withdrawing address record for 169.254.213.79 on eth0. Dec 30 06:20:58 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:20:58 volumio volumio[19730]: info: Volumio Network Manager: Network status updated: 1 Dec 30 06:20:58 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:58 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:20:58 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:20:58 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:20:58 volumio volumio[19730]: info: VolumeController:: Volume=100 Mute =false Dec 30 06:20:58 volumio volumio[19730]: info: CoreStateMachine::pushState Dec 30 06:20:58 volumio volumio[19730]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::volumioPushState Dec 30 06:20:58 volumio volumio[19730]: info: CoreStateMachine::updateTrackBlock Dec 30 06:20:58 volumio volumio[19730]: info: CorePlayQueue::getTrackBlock Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 06:20:58 volumio volumio[19730]: info: Reloading queue from file Dec 30 06:20:58 volumio volumio[19730]: info: CoreStateMachine::setRepeat null single undefined Dec 30 06:20:58 volumio volumio[19730]: info: CoreStateMachine::pushState Dec 30 06:20:58 volumio volumio[19730]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::volumioPushState Dec 30 06:20:58 volumio volumio[19730]: info: CoreStateMachine::setRandom null Dec 30 06:20:58 volumio volumio[19730]: info: CoreStateMachine::pushState Dec 30 06:20:58 volumio volumio[19730]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::volumioPushState Dec 30 06:20:58 volumio volumio[19730]: info: Setting Device type: Raspberry PI Dec 30 06:20:58 volumio volumio[19730]: info: VolumeController:: Volume=100 Mute =false Dec 30 06:20:58 volumio volumio[19730]: info: CoreStateMachine::pushState Dec 30 06:20:58 volumio volumio[19730]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::volumioPushState Dec 30 06:20:58 volumio volumio[19730]: info: Completed loading Core Plugins Dec 30 06:20:58 volumio volumio[19730]: info: Preparing to generate the ALSA configuration file Dec 30 06:20:58 volumio sudo[20072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 30 06:20:58 volumio sudo[20072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:58 volumio volumio[19730]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Dec 30 06:20:58 volumio volumio[19730]: info: Discovery: Found device Volumio Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::volumioGetState Dec 30 06:20:58 volumio volumio[19730]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:58 volumio volumio[19730]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Dec 30 06:20:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Dec 30 06:20:58 volumio volumio[19730]: info: Discovery: Found device Volumio Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::volumioGetState Dec 30 06:20:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:58 volumio volumio[19730]: info: CorePlayQueue::getTrack 0 Dec 30 06:20:58 volumio volumio[19730]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 06:20:58 volumio volumio[19730]: info: Reading ALSA contributions from plugins. Dec 30 06:20:58 volumio volumio[19730]: info: Asound.conf file unchanged, so no further update is needed Dec 30 06:20:58 volumio volumio[19730]: info: Output device has changed, restarting MPD Dec 30 06:20:58 volumio volumio[19730]: info: Output device has changed, restarting Shairport Sync Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:58 volumio sudo[20076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 06:20:58 volumio sudo[20078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 06:20:58 volumio sudo[20076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:58 volumio sudo[20078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:58 volumio sudo[20076]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:58 volumio volumio[19730]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 06:20:58 volumio volumio[19730]: info: ___________ START PLUGINS ___________ Dec 30 06:20:58 volumio volumio[19730]: info: ControllerMpd::onStart: Initializing MPD Dec 30 06:20:58 volumio volumio[19730]: info: Creating MPD Configuration file Dec 30 06:20:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:20:58 volumio go-librespot[20074]: go-librespot daemon starting... Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:58 volumio volumio[19730]: info: [1767097258938] CoreMusicLibrary::Adding element Media Servers Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:58 volumio sudo[20087]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 06:20:58 volumio sudo[20087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:58 volumio sudo[20087]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:58 volumio sudo[20094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:58 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:58 volumio sudo[20094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:20:58 volumio sudo[20072]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:58 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 30 06:20:58 volumio go-librespot[20086]: time="2025-12-30T06:20:58-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:20:58 volumio go-librespot[20086]: time="2025-12-30T06:20:58-06:00" level=debug msg="app state loaded" Dec 30 06:20:58 volumio go-librespot[20086]: time="2025-12-30T06:20:58-06:00" level=debug msg="stored credentials not found" Dec 30 06:20:58 volumio go-librespot[20086]: time="2025-12-30T06:20:58-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:20:59 volumio volumio[19730]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:59 volumio volumio[19730]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:59 volumio volumio[19730]: info: [1767097259057] CoreMusicLibrary::Adding element Last_100 Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:59 volumio volumio[19730]: info: [1767097259073] CoreMusicLibrary::Adding element Webradio Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 06:20:59 volumio volumio[19730]: info: Initializing BBC Radios Dec 30 06:20:59 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 30 06:20:59 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 06:20:59 volumio systemd[1]: mpd.service: Consumed 5.240s CPU time. Dec 30 06:20:59 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 30 06:20:59 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 06:20:59 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:20:59 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:59 volumio volumio[19730]: info: [1767097259182] CoreMusicLibrary::Adding element Bandcamp Discover Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:59 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:59 volumio volumio[19730]: info: [1767097259213] CoreMusicLibrary::Adding element SoundCloud Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source SoundCloud Dec 30 06:20:59 volumio volumio[19730]: info: Creating Spotify config file Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:20:59 volumio go-librespot[20086]: time="2025-12-30T06:20: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]" Dec 30 06:20:59 volumio go-librespot[20086]: time="2025-12-30T06:20: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]" Dec 30 06:20:59 volumio go-librespot[20086]: time="2025-12-30T06:20: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]" Dec 30 06:20:59 volumio go-librespot[20086]: time="2025-12-30T06:20:59-06:00" level=info msg="zeroconf server listening on port 44367" Dec 30 06:20:59 volumio go-librespot[20086]: time="2025-12-30T06:20:59-06:00" level=debug msg="obtained new client token: AABo/vuSO4620u45DcZNOcXxr3+j1f6iKtDXL+5Rm50KFyovNPEjgsL21yGtFtTDi4AQBOkiAepQWlRm0uVGkPFsay86hdW0nGQcxBNLf38RwqNMGPizTf5wahP6mwFKpxtkKS1x48WHuue5eC5PUT2NnxSL1Al1qLnH68pG6MUS7lRKqz8DUNYIhcQHpebFKsZWZcu6p2kklt2vWFURhhm0Z94Sm5VNQPojQpmVZdaEsDfVFWA+p6yXtw==" Dec 30 06:20:59 volumio sudo[20121]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 06:20:59 volumio sudo[20121]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 06:20:59 volumio sudo[20121]: pam_unix(sudo:session): session closed for user root Dec 30 06:20:59 volumio go-librespot[20086]: time="2025-12-30T06:20:59-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:20:59 volumio go-librespot[20086]: time="2025-12-30T06:20:59-06:00" level=debug msg="completed keyexchange" Dec 30 06:20:59 volumio go-librespot[20086]: time="2025-12-30T06:20:59-06:00" level=debug msg="completed challenge" Dec 30 06:20:59 volumio go-librespot[20086]: time="2025-12-30T06:20: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 " Dec 30 06:20:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:20:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:20:59 volumio volumio[19730]: info: [squeezelite_mc] Starting proxy server... Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:59 volumio volumio[19730]: info: [1767097259595] CoreMusicLibrary::Adding element YouTube2 Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source SoundCloud Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube2 Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:59 volumio volumio[19730]: info: [1767097259614] CoreMusicLibrary::Adding element YouTube Music Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source SoundCloud Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube2 Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube Music Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:59 volumio volumio[19730]: info: [1767097259632] CoreMusicLibrary::Adding element Podcast Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source SoundCloud Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube2 Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube Music Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Podcast Dec 30 06:20:59 volumio volumio[19730]: info: Loading i18n strings for locale en Dec 30 06:20:59 volumio volumio[19730]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Dec 30 06:20:59 volumio volumio[19730]: Updating browse sources language Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source SoundCloud Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube2 Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube Music Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Podcast Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source SoundCloud Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube2 Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube Music Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Podcast Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:20:59 volumio volumio[19730]: info: [1767097259680] CoreMusicLibrary::Adding element Volusonic Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Bandcamp Discover Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source SoundCloud Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube2 Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source YouTube Music Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Podcast Dec 30 06:20:59 volumio volumio[19730]: Cannot find translation for source Volusonic Dec 30 06:20:59 volumio volumio[19730]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 30 06:20:59 volumio volumio[19730]: info: Volumio Calling Home Dec 30 06:20:59 volumio kernel: hwmon hwmon1: Voltage normalised Dec 30 06:20:59 volumio volumio[19730]: info: [squeezelite_mc] Proxy server started on port 43157 Dec 30 06:20:59 volumio volumio[19730]: info: Preparing to generate the ALSA configuration file Dec 30 06:20:59 volumio volumio[19730]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 06:20:59 volumio volumio[19730]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 06:20:59 volumio volumio[19730]: info: Reading ALSA contributions from plugins. Dec 30 06:20:59 volumio volumio[19730]: info: MPD Permissions set Dec 30 06:20:59 volumio volumio[19730]: info: MPD Permissions set Dec 30 06:20:59 volumio volumio[19730]: info: Upmpdcli Daemon Started Dec 30 06:20:59 volumio volumio[19730]: info: Spotify config file written Dec 30 06:21:00 volumio sudo[20132]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 06:21:00 volumio sudo[20132]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:00 volumio volumio[19730]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Dec 30 06:21:00 volumio volumio[19730]: info: VolumeController:: Volume=100 Mute =false Dec 30 06:21:00 volumio volumio[19730]: info: CoreStateMachine::pushState Dec 30 06:21:00 volumio volumio[19730]: info: CorePlayQueue::getTrack 0 Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::volumioPushState Dec 30 06:21:00 volumio volumio[19730]: info: [squeezelite_mc] Server discovery started Dec 30 06:21:00 volumio volumio[19730]: info: [squeezelite_mc] Player finder started Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Dec 30 06:21:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:21:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio go-librespot[20135]: go-librespot daemon starting... Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio sudo[20132]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: No need to fix Spotify hosts Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-06:00" level=debug msg="app state loaded" Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-06:00" level=debug msg="stored credentials not found" Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:21:00 volumio volumio[19730]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 30 06:21:00 volumio volumio[19730]: info: Volumio called home Dec 30 06:21:00 volumio volumio[19730]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Dec 30 06:21:00 volumio volumio[19730]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Dec 30 06:21:00 volumio volumio[19730]: 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 Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-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]" Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-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]" Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-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]" Dec 30 06:21:00 volumio volumio[19730]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 06:21:00 volumio volumio[19730]: SPOTIFY: BQBpXYZ7_RNprDTc8IKq0JGvUv4ptZ8o2YPiaQZI1mtzrySFfNAtQTvK4CaOhfVKiX6zb20EIr0fFJxNHly0CruCN2GUgCYSvgSmSusrpolJxMlLKtnK8NaH-qeFQk0hRMn3oCL0rmDGV60Iq0PJogbry-2OYh1zzKRio910oJq_NvozN8GxEdrFJkeI9H5IrA0ChqfHdMN_7XHyd--prvo6ETGPyxc5yEiqei0 Dec 30 06:21:00 volumio volumio[19730]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-06:00" level=info msg="zeroconf server listening on port 34839" Dec 30 06:21:00 volumio volumio[19730]: info: New Spotify access token = BQBpXYZ7_RNprDTc8IKq0JGvUv4ptZ8o2YPiaQZI1mtzrySFfNAtQTvK4CaOhfVKiX6zb20EIr0fFJxNHly0CruCN2GUgCYSvgSmSusrpolJxMlLKtnK8NaH-qeFQk0hRMn3oCL0rmDGV60Iq0PJogbry-2OYh1zzKRio910oJq_NvozN8GxEdrFJkeI9H5IrA0ChqfHdMN_7XHyd--prvo6ETGPyxc5yEiqei0 Dec 30 06:21:00 volumio volumio[19730]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 30 06:21:00 volumio sudo[20156]: 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 Dec 30 06:21:00 volumio sudo[20156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:00 volumio sudo[20156]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:00 volumio volumio[19730]: info: Starting Shairport Sync Dec 30 06:21:00 volumio volumio[19730]: info: Starting Shairport Sync Dec 30 06:21:00 volumio volumio[19730]: info: Starting Shairport Sync Dec 30 06:21:00 volumio sudo[20159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 06:21:00 volumio sudo[20159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-06:00" level=debug msg="obtained new client token: AABAwotgk1lsly8uyzkZ9ZNHMxJ0Mfs/8sd4QcETys5XChZIHGxYL4HXNhxOycR2o+3JojCfzQvgADGep4sNTIVsXLwLcffTwII8QyC3LV6M3jb8CIYkkdgtREC/zD9C45TiLK123cijqlQsa9ErpDsNQ8FIba3Owrn/747OHGOkIo5LYDbpYK8X6rKPPw/Q6MkL4tGAb3lCIZqbkpTAhtdxnedb+Emi0WjSUWpMHw/W2qIPycUk/YrIDw==" Dec 30 06:21:00 volumio volumio[19730]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Dec 30 06:21:00 volumio sudo[20161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 06:21:00 volumio sudo[20161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:00 volumio sudo[20163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 06:21:00 volumio sudo[20163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:21:00 volumio volumio[19730]: info: Asound.conf file unchanged, so no further update is needed Dec 30 06:21:00 volumio volumio[19730]: info: Output device has changed, restarting MPD Dec 30 06:21:00 volumio sudo[20168]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Dec 30 06:21:00 volumio sudo[20168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-06:00" level=debug msg="completed keyexchange" Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-06:00" level=debug msg="completed challenge" Dec 30 06:21:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 06:21:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 06:21:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 06:21:00 volumio systemd[1]: shairport-sync.service: Consumed 1.959s CPU time. Dec 30 06:21:00 volumio sudo[20168]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:00 volumio volumio[19730]: info: Output device has changed, restarting Shairport Sync Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:00 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:21:00 volumio sudo[20171]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 06:21:00 volumio sudo[20171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:00 volumio go-librespot[20142]: time="2025-12-30T06:21:00-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 06:21:00 volumio sudo[20171]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:00 volumio sudo[20174]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 06:21:00 volumio sudo[20174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:00 volumio volumio[19730]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 06:21:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 06:21:00 volumio sudo[20163]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:21:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:21:00 volumio sudo[20161]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:00 volumio sudo[20159]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:00 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 30 06:21:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 06:21:00 volumio systemd[1]: mpd.service: Consumed 1.605s CPU time. Dec 30 06:21:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 30 06:21:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 06:21:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 06:21:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 06:21:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 06:21:01 volumio volumio[19730]: info: MPD Permissions set Dec 30 06:21:01 volumio volumio[19730]: info: Shairport-Sync Started Dec 30 06:21:01 volumio volumio[19730]: Error adding Membership: Error: addMembership EINVAL Dec 30 06:21:01 volumio volumio[19730]: info: Shairport-Sync Started Dec 30 06:21:01 volumio volumio[19730]: info: Shairport-Sync Started Dec 30 06:21:01 volumio volumio[19730]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Dec 30 06:21:01 volumio sudo[20204]: 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 Dec 30 06:21:01 volumio sudo[20204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:01 volumio sudo[20204]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:01 volumio volumio[19730]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:01 volumio sudo[20207]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 30 06:21:01 volumio sudo[20207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:01 volumio systemd[1]: Reloading. Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::volumioGetState Dec 30 06:21:01 volumio volumio[19730]: info: CorePlayQueue::getTrack 0 Dec 30 06:21:01 volumio volumio[19730]: 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"} Dec 30 06:21:01 volumio volumio[19730]: info: Spotify Successfully logged in Dec 30 06:21:01 volumio sudo[20201]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 06:21:01 volumio sudo[20201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 06:21:01 volumio volumio[19730]: info: [1767097261339] CoreMusicLibrary::Adding element Spotify Dec 30 06:21:01 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 06:21:01 volumio sudo[20201]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:01 volumio volumio[19730]: Cannot find translation for source Bandcamp Discover Dec 30 06:21:01 volumio volumio[19730]: Cannot find translation for source SoundCloud Dec 30 06:21:01 volumio volumio[19730]: Cannot find translation for source YouTube2 Dec 30 06:21:01 volumio volumio[19730]: Cannot find translation for source YouTube Music Dec 30 06:21:01 volumio volumio[19730]: Cannot find translation for source Podcast Dec 30 06:21:01 volumio volumio[19730]: Cannot find translation for source Volusonic Dec 30 06:21:01 volumio volumio[19730]: Cannot find translation for source Spotify Dec 30 06:21:01 volumio volumio[19730]: info: Starting Shairport Sync Dec 30 06:21:01 volumio sudo[20218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 06:21:01 volumio sudo[20218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:01 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 06:21:02 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:02 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:02 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 06:21:02 volumio volumio[19730]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 06:21:03 volumio volumio[19730]: info: go-librespot daemon successfully initialized Dec 30 06:21:03 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.178.76 Dec 30 06:21:03 volumio avahi-daemon[664]: Registering new address record for 169.254.178.76 on eth0.IPv4. Dec 30 06:21:03 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:21:03 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.178.76 Dec 30 06:21:03 volumio volumio-remote-updater[702]: [2025-12-30 06:21:03] [connect] Successful connection Dec 30 06:21:03 volumio volumio-remote-updater[702]: [2025-12-30 06:21:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767097263 101 Dec 30 06:21:03 volumio volumio[19730]: 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: 3 Dec 30 06:21:03 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. Dec 30 06:21:03 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. Dec 30 06:21:04 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.178.76 Dec 30 06:21:04 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.178.76 Dec 30 06:21:04 volumio avahi-daemon[664]: Withdrawing address record for 169.254.178.76 on eth0. Dec 30 06:21:04 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:21:04 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:21:04 volumio sudo[20207]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:04 volumio volumio[19730]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 06:21:04 volumio sudo[20285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 06:21:04 volumio sudo[20285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Dec 30 06:21:04 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:04 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:21:04 volumio sudo[20285]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:04 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:21:04 volumio volumio[19730]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Dec 30 06:21:04 volumio sudo[20290]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Dec 30 06:21:04 volumio sudo[20290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:21:04 volumio go-librespot[20288]: go-librespot daemon starting... Dec 30 06:21:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 06:21:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 06:21:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 06:21:04 volumio systemd[1]: shairport-sync.service: Consumed 1.490s CPU time. Dec 30 06:21:04 volumio go-librespot[20292]: time="2025-12-30T06:21:04-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:21:04 volumio go-librespot[20292]: time="2025-12-30T06:21:04-06:00" level=debug msg="app state loaded" Dec 30 06:21:04 volumio go-librespot[20292]: time="2025-12-30T06:21:04-06:00" level=debug msg="stored credentials not found" Dec 30 06:21:04 volumio go-librespot[20292]: time="2025-12-30T06:21:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:21:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 06:21:04 volumio sudo[20218]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:04 volumio volumio[19730]: info: Shairport-Sync Started Dec 30 06:21:04 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:04 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:21:04 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:04 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 30 06:21:05 volumio systemd[1]: squeezelite.service: Deactivated successfully. Dec 30 06:21:05 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 30 06:21:05 volumio sudo[20290]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:05 volumio go-librespot[20292]: time="2025-12-30T06:21:05-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]" Dec 30 06:21:05 volumio go-librespot[20292]: time="2025-12-30T06:21:05-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]" Dec 30 06:21:05 volumio go-librespot[20292]: time="2025-12-30T06:21:05-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]" Dec 30 06:21:05 volumio go-librespot[20292]: time="2025-12-30T06:21:05-06:00" level=info msg="zeroconf server listening on port 34297" Dec 30 06:21:05 volumio go-librespot[20292]: time="2025-12-30T06:21:05-06:00" level=debug msg="obtained new client token: AABH8VPX0HUY4HhYIkl6Z2H4RuHvRO2NTjEEIr9rnVm716x0gPGDMn5gyaJQQsk/zBuP5aa/8MJjM1ltLjY7MSgtJutOyXMm/mQa6mUL1iwNh5AvEk+Dnr8baxm8Do3zcP+dqXK0+ammHtWZfjlYds/4p4IZ5t45ISghDeBjpaJ+phAmIv6Z9aZAIk3nx/8kwKKMoUdCYMIyacs5mIzL78QB3GUAVtpGg7Jg2BPS9HAY4ToutrQ9deI=" Dec 30 06:21:05 volumio go-librespot[20292]: time="2025-12-30T06:21:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:21:05 volumio go-librespot[20292]: time="2025-12-30T06:21:05-06:00" level=debug msg="completed keyexchange" Dec 30 06:21:05 volumio go-librespot[20292]: time="2025-12-30T06:21:05-06:00" level=debug msg="completed challenge" Dec 30 06:21:05 volumio go-librespot[20292]: time="2025-12-30T06:21:05-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 06:21:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:21:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:21:05 volumio volumio[19730]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 06:21:05 volumio sudo[20316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 06:21:05 volumio sudo[20316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:05 volumio sudo[20316]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:05 volumio volumio[19730]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Dec 30 06:21:05 volumio sudo[20320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Dec 30 06:21:05 volumio sudo[20320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:05 volumio sudo[20320]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:05 volumio volumio[19730]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Dec 30 06:21:05 volumio sudo[20323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Dec 30 06:21:05 volumio sudo[20323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:05 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Dec 30 06:21:05 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Dec 30 06:21:05 volumio sudo[20323]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:06 volumio volumio[19730]: info: Initializing connection to go-librespot Websocket Dec 30 06:21:06 volumio volumio[19730]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 06:21:06 volumio volumio[19730]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 06:21:06 volumio sudo[20330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 06:21:06 volumio sudo[20330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:06 volumio sudo[20330]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:07 volumio volumio[19730]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 06:21:07 volumio sudo[20333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 06:21:07 volumio sudo[20333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:07 volumio sudo[20333]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:07 volumio mpd[20283]: 2025-12-30T06:21:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 30 06:21:07 volumio volumio[19730]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 06:21:07 volumio sudo[20336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 06:21:07 volumio sudo[20336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:07 volumio sudo[20336]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 30 06:21:07 volumio sudo[20174]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:07 volumio sudo[20094]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:07 volumio sudo[20078]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:08 volumio volumio[19730]: error: MPD error: The expression evaluated to a falsy value: Dec 30 06:21:08 volumio volumio[19730]: assert.ok(self.idling) Dec 30 06:21:08 volumio volumio[19730]: error: The expression evaluated to a falsy value: Dec 30 06:21:08 volumio volumio[19730]: assert.ok(self.idling) Dec 30 06:21:08 volumio volumio[19730]: error: MPD error: The expression evaluated to a falsy value: Dec 30 06:21:08 volumio volumio[19730]: assert.ok(self.idling) Dec 30 06:21:08 volumio volumio[19730]: error: The expression evaluated to a falsy value: Dec 30 06:21:08 volumio volumio[19730]: assert.ok(self.idling) Dec 30 06:21:08 volumio volumio[19730]: error: updateQueue error: null Dec 30 06:21:08 volumio volumio[19730]: info: MPD running with PID20283 Dec 30 06:21:08 volumio volumio[19730]: ,establishing connection Dec 30 06:21:08 volumio volumio[19730]: error: updateQueue error: null Dec 30 06:21:08 volumio kernel: hwmon hwmon1: Voltage normalised Dec 30 06:21:08 volumio volumio[19730]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 06:21:08 volumio sudo[20345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 06:21:08 volumio sudo[20345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:08 volumio sudo[20345]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Dec 30 06:21:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:21:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:21:08 volumio go-librespot[20347]: go-librespot daemon starting... Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-06:00" level=debug msg="app state loaded" Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-06:00" level=debug msg="stored credentials not found" Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-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]" Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-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]" Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-06:00" level=info msg="zeroconf server listening on port 40589" Dec 30 06:21:08 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.149.98 Dec 30 06:21:08 volumio avahi-daemon[664]: Registering new address record for 169.254.149.98 on eth0.IPv4. Dec 30 06:21:08 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-06:00" level=debug msg="obtained new client token: AACShXVOao5dikBD82hSzX1+HffAMGV/u9ypQEZ/WcQvdvuVQ4w7gbkfsa2YVzY3SCGmwZoQcQy0JSFWXxPMG9eMTsEtMn7QXBEPRca1zgiiJNgcZwkhviQtfVW5EL7bWyIwH5NHgDy0ay7zW21SIugWzl2Mv/UH09YGCHxQboLX30yMIfawlQtz770OHRq0ehDX94GYZILZ7OQgE04vByaxoUsiUjUwl19bR2x5Zr4nuK0j/b0CSNHflw==" Dec 30 06:21:08 volumio volumio[19730]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Dec 30 06:21:08 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:08 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:21:08 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:21:08 volumio sudo[20372]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Dec 30 06:21:08 volumio sudo[20372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-06:00" level=debug msg="completed keyexchange" Dec 30 06:21:08 volumio go-librespot[20348]: time="2025-12-30T06:21:08-06:00" level=debug msg="completed challenge" Dec 30 06:21:08 volumio sudo[20372]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:08 volumio volumio[19730]: info: Completed starting Core Plugins Dec 30 06:21:08 volumio volumio[19730]: info: ------------------------------------------- Dec 30 06:21:08 volumio volumio[19730]: info: ----- MyVolumio plugins startup ---- Dec 30 06:21:08 volumio volumio[19730]: info: ------------------------------------------- Dec 30 06:21:08 volumio volumio[19730]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 30 06:21:09 volumio go-librespot[20348]: time="2025-12-30T06:21:09-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 " Dec 30 06:21:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:21:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:21:09 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.149.98 Dec 30 06:21:09 volumio volumio[19730]: info: Initializing connection to go-librespot Websocket Dec 30 06:21:09 volumio volumio[19730]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 06:21:09 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.149.98 Dec 30 06:21:09 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.149.98 Dec 30 06:21:09 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:21:09 volumio avahi-daemon[664]: Withdrawing address record for 169.254.149.98 on eth0. Dec 30 06:21:09 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:21:09 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:09 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:21:09 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:10 volumio sudo[20391]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 06:21:10 volumio sudo[20391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:10 volumio sudo[20393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 06:21:10 volumio sudo[20393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:10 volumio sudo[20395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 06:21:10 volumio sudo[20395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 06:21:11 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 30 06:21:11 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 30 06:21:11 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 30 06:21:11 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 30 06:21:11 volumio sudo[20393]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:11 volumio mpd_monitor.sh[20399]: MPD Monitor Service: Starting MPD Monitor Service Dec 30 06:21:11 volumio sudo[20391]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:11 volumio volumio[19730]: info: Successfully started MPD Monitor Dec 30 06:21:11 volumio sudo[20395]: pam_unix(sudo:session): session closed for user root Dec 30 06:21:11 volumio volumio[19730]: info: Successfully started MPD Monitor Dec 30 06:21:11 volumio volumio[19730]: info: Successfully started MPD Monitor Dec 30 06:21:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Dec 30 06:21:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:21:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:21:12 volumio go-librespot[20407]: go-librespot daemon starting... Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=debug msg="app state loaded" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=debug msg="stored credentials not found" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:21:12 volumio volumio[19730]: info: Initializing connection to go-librespot Websocket Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-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]" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-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]" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=debug msg="new websocket client" Dec 30 06:21:12 volumio volumio[19730]: info: Connection to go-librespot Websocket established Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=info msg="zeroconf server listening on port 41603" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=debug msg="obtained new client token: AAD7msZ+Qi8BNkxkGK/Cw1fuxYFb9gfJtrCEY38XXIaBMc4YaKIC2pYymm9TcvbB7rK4LRKun+QrKrsvNS07RrCxgqtUgvIOdRMbDXmgVTQiGWqTgY2JMWpQEy6hSQ0OG6eD2x1sqhACD9ZNeSGKAqQrdYXPq9ej3a8EVj0ws3oAFteySyR/dOfN1bMDukem3gyz/gfh9OXcbZkMfm2adJrszmuZEsOFN9CT5/rDMqFqDAfWfROq+FMGSw==" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=debug msg="completed keyexchange" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=debug msg="completed challenge" Dec 30 06:21:12 volumio go-librespot[20418]: time="2025-12-30T06:21:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 06:21:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:21:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:21:12 volumio volumio[19730]: info: Connection to go-librespot Websocket closed Dec 30 06:21:14 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 30 06:21:15 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.55.110 Dec 30 06:21:15 volumio avahi-daemon[664]: Registering new address record for 169.254.55.110 on eth0.IPv4. Dec 30 06:21:15 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Dec 30 06:21:15 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:15 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:21:15 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:15 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.55.110 Dec 30 06:21:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Dec 30 06:21:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:21:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 06:21:16 volumio go-librespot[20442]: go-librespot daemon starting... Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=info msg="running go-librespot 0.4.0" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=debug msg="app state loaded" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=debug msg="stored credentials not found" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 06:21:16 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.55.110 Dec 30 06:21:16 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.55.110 Dec 30 06:21:16 volumio avahi-daemon[664]: Withdrawing address record for 169.254.55.110 on eth0. Dec 30 06:21:16 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Dec 30 06:21:16 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:16 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Dec 30 06:21:16 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Dec 30 06:21:16 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=info msg="zeroconf server listening on port 45275" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=debug msg="obtained new client token: AAAT/FVzSk4EgVzvC8a29dOEvw4xo4e+17WEjHa2OXTgsTKOcd4BzEnnx387wHIhMUpfMjMuErjcegOu0olZnlxDU5fuUPSbCaHWSA3s9rAHeq5TwLLDTdxL77vUZYybML8+68Po+V1DOzaeEdubcV2WFEW6JR6QQ5FM9yWsKw7PArSNd3Qdxv63D81qgf+zFYCRbXTrQAPKHI3efcd3zhFjsZIMMKVxXMtYUtZuIMc5Q5B8dO5MUssqsA==" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=debug msg="completed keyexchange" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=debug msg="completed challenge" Dec 30 06:21:16 volumio go-librespot[20443]: time="2025-12-30T06:21:16-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 30 06:21:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 06:21:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 06:21:17 volumio volumio[19730]: info: Getting Spotify volume Dec 30 06:21:17 volumio volumio[19730]: info: Initializing connection to go-librespot Websocket Dec 30 06:21:17 volumio volumio[19730]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 06:21:17 volumio volumio[19730]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 06:21:17 volumio volumio[19730]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 30 06:21:17 volumio volumio[19730]: errno: -111, Dec 30 06:21:17 volumio volumio[19730]: code: 'ECONNREFUSED', Dec 30 06:21:17 volumio volumio[19730]: syscall: 'connect', Dec 30 06:21:17 volumio volumio[19730]: address: '127.0.0.1', Dec 30 06:21:17 volumio volumio[19730]: port: 9879, Dec 30 06:21:17 volumio volumio[19730]: response: undefined Dec 30 06:21:17 volumio volumio[19730]: } Dec 30 06:21:17 volumio volumio[19730]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 06:21:18 volumio sudo[20480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-30 06:20' Dec 30 06:21:18 volumio sudo[20480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025" VOLUMIO_VERSION="4.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"