Jan 11 00:32:00 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.218.41 Jan 11 00:32:00 volumio avahi-daemon[664]: Registering new address record for 169.254.218.41 on eth0.IPv4. Jan 11 00:32:00 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:32:00 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:00 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:00 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.218.41 Jan 11 00:32:01 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.218.41 Jan 11 00:32:01 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.218.41 Jan 11 00:32:01 volumio avahi-daemon[664]: Withdrawing address record for 169.254.218.41 on eth0. Jan 11 00:32:01 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:32:01 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:32:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96. Jan 11 00:32:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:01 volumio go-librespot[24828]: go-librespot daemon starting... Jan 11 00:32:01 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:01 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:01 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=debug msg="app state loaded" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:01 volumio volumio[24156]: info: Initializing connection to go-librespot Websocket Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=debug msg="new websocket client" Jan 11 00:32:01 volumio volumio[24156]: info: Connection to go-librespot Websocket established Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=info msg="zeroconf server listening on port 40367" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=debug msg="obtained new client token: AABuKWasSwkMQqWu231ktTdGVMAmU5vYB80YePW9MnpPLcoZwJaIHSsxygS0OCeHqLDe/WgVVKnbvaI+i3yqLoZUhWEDYVmHjb/DGc6YU1CoaObt00ItjrTFFheR1O65pZxbdpGs+3q6FDPXhgdDGT6sXWwHmZ0pGaVXq4JKv8p+tm62WVfDeh+xb+K0gzkuny9F2A3SsVHF1Rb0seAicvO29ewsgHaCeFeR8ZOkDq2w67DebXLSjG4VoA==" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=debug msg="completed challenge" Jan 11 00:32:01 volumio go-librespot[24829]: time="2026-01-11T00:32:01-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:01 volumio volumio[24156]: info: Connection to go-librespot Websocket closed Jan 11 00:32:03 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 00:32:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97. Jan 11 00:32:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:04 volumio go-librespot[24837]: go-librespot daemon starting... Jan 11 00:32:04 volumio go-librespot[24838]: time="2026-01-11T00:32:04-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:04 volumio go-librespot[24838]: time="2026-01-11T00:32:04-06:00" level=debug msg="app state loaded" Jan 11 00:32:04 volumio go-librespot[24838]: time="2026-01-11T00:32:04-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:04 volumio go-librespot[24838]: time="2026-01-11T00:32:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:05 volumio go-librespot[24838]: time="2026-01-11T00:32: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]" Jan 11 00:32:05 volumio go-librespot[24838]: time="2026-01-11T00:32: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]" Jan 11 00:32:05 volumio go-librespot[24838]: time="2026-01-11T00:32: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]" Jan 11 00:32:05 volumio go-librespot[24838]: time="2026-01-11T00:32:05-06:00" level=info msg="zeroconf server listening on port 35245" Jan 11 00:32:05 volumio go-librespot[24838]: time="2026-01-11T00:32:05-06:00" level=debug msg="obtained new client token: AACmImEPQsEhH3JW5sZYhFdp/3yibb3wHvGWdQGgM2t0p/uOd8hL8daTQKyg3l0PTeHBrkqQguBRsCAROFRHi9NYMelEmvZ2AlwEl7uEbAgyH6yvis54DPXyaelNdVaKWmNNu3KawtJ8ujSa9s1XzieubA27qzDnyWmxnbb8UdQo6XL5l5Rzw312DOU2FsIF+8A+E74d6AK4FE4S+TtqVha5r9+MdqFohmCAcNNwT7FKjaTRreOQr+l++Q==" Jan 11 00:32:05 volumio go-librespot[24838]: time="2026-01-11T00:32:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:05 volumio go-librespot[24838]: time="2026-01-11T00:32:05-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:05 volumio go-librespot[24838]: time="2026-01-11T00:32:05-06:00" level=debug msg="completed challenge" Jan 11 00:32:05 volumio go-librespot[24838]: time="2026-01-11T00:32: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 " Jan 11 00:32:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:05 volumio volumio[24156]: info: Getting Spotify volume Jan 11 00:32:05 volumio volumio[24156]: info: Initializing connection to go-librespot Websocket Jan 11 00:32:05 volumio volumio[24156]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 00:32:05 volumio volumio[24156]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 00:32:05 volumio volumio[24156]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 11 00:32:05 volumio volumio[24156]: errno: -111, Jan 11 00:32:05 volumio volumio[24156]: code: 'ECONNREFUSED', Jan 11 00:32:05 volumio volumio[24156]: syscall: 'connect', Jan 11 00:32:05 volumio volumio[24156]: address: '127.0.0.1', Jan 11 00:32:05 volumio volumio[24156]: port: 9879, Jan 11 00:32:05 volumio volumio[24156]: response: undefined Jan 11 00:32:05 volumio volumio[24156]: } Jan 11 00:32:05 volumio volumio[24156]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 00:32:06 volumio sudo[24859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-11 00:31' Jan 11 00:32:06 volumio sudo[24859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:06 volumio sudo[24859]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:06 volumio volumio-remote-updater[14193]: [2026-01-11 00:32:06] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 11 00:32:06 volumio volumio-remote-updater[14193]: [2026-01-11 00:32:06] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 11 00:32:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 00:32:06 volumio systemd[1]: volumio.service: Consumed 53.100s CPU time. Jan 11 00:32:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 11 00:32:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 11 00:32:06 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.20.228 Jan 11 00:32:06 volumio avahi-daemon[664]: Registering new address record for 169.254.20.228 on eth0.IPv4. Jan 11 00:32:06 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:32:06 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 18870. Jan 11 00:32:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 11 00:32:07 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 11 00:32:07 volumio systemd[1]: volumio.service: Consumed 53.100s CPU time. Jan 11 00:32:07 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 11 00:32:07 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:07 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:07 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 11 00:32:07 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.20.228 Jan 11 00:32:08 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 00:32:08 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.20.228 Jan 11 00:32:08 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.20.228 Jan 11 00:32:08 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:32:08 volumio avahi-daemon[664]: Withdrawing address record for 169.254.20.228 on eth0. Jan 11 00:32:08 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:08 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:08 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:08 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:32:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 98. Jan 11 00:32:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:08 volumio go-librespot[24924]: go-librespot daemon starting... Jan 11 00:32:08 volumio go-librespot[24925]: time="2026-01-11T00:32:08-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:08 volumio go-librespot[24925]: time="2026-01-11T00:32:08-06:00" level=debug msg="app state loaded" Jan 11 00:32:08 volumio go-librespot[24925]: time="2026-01-11T00:32:08-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:08 volumio go-librespot[24925]: time="2026-01-11T00:32:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:09 volumio volumio[24892]: info: ------------------------------------------- Jan 11 00:32:09 volumio volumio[24892]: info: ----- Volumio3 ---- Jan 11 00:32:09 volumio volumio[24892]: info: ------------------------------------------- Jan 11 00:32:09 volumio volumio[24892]: info: ----- System startup ---- Jan 11 00:32:09 volumio volumio[24892]: info: ------------------------------------------- Jan 11 00:32:09 volumio go-librespot[24925]: time="2026-01-11T00:32:09-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:32:09 volumio go-librespot[24925]: time="2026-01-11T00:32:09-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:32:09 volumio go-librespot[24925]: time="2026-01-11T00:32:09-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:32:09 volumio go-librespot[24925]: time="2026-01-11T00:32:09-06:00" level=info msg="zeroconf server listening on port 40333" Jan 11 00:32:09 volumio go-librespot[24925]: time="2026-01-11T00:32:09-06:00" level=debug msg="obtained new client token: AACoKganOpE47RpnzRVHfLLG4hoiXIUXN0n94ZHujGvzgK3EvyuEsjxPvUraZqjhsPy9N/9v1nRpTCIxz34LFl5AiDZtj5bStMUosIAcVChW8LgBraEgtXzatlvVZhpuq3Q4qcIZNrelO6/rFDOt0QjoNHiCpXhu+NWqCdxAwBsqnhNA/JrLIXtmBsfw11HqvKcGS0hW+TM2lL+ORqrpTd0nKynqjU8HQmmJUG23+v1zC13ydkA6dRg=" Jan 11 00:32:09 volumio go-librespot[24925]: time="2026-01-11T00:32:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:09 volumio go-librespot[24925]: time="2026-01-11T00:32:09-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:09 volumio go-librespot[24925]: time="2026-01-11T00:32:09-06:00" level=debug msg="completed challenge" Jan 11 00:32:09 volumio go-librespot[24925]: time="2026-01-11T00:32: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 " Jan 11 00:32:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:09 volumio volumio[24892]: info: MYVOLUMIO Environment detected Jan 11 00:32:09 volumio volumio[24892]: info: Plugin folders cleanup Jan 11 00:32:09 volumio volumio[24892]: info: Scanning into folder /volumio/app/plugins/ Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category audio_interface Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category miscellanea Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category music_service Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category plugins.json Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category system_controller Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category user_interface Jan 11 00:32:09 volumio volumio[24892]: info: Scanning into folder /data/plugins/ Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category audio_interface Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category music_service Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category system_controller Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category system_hardware Jan 11 00:32:09 volumio volumio[24892]: info: Scanning category user_interface Jan 11 00:32:09 volumio volumio[24892]: info: Plugin folders cleanup completed Jan 11 00:32:09 volumio volumio[24892]: info: ------------------------------------------- Jan 11 00:32:09 volumio volumio[24892]: info: ----- Core plugins startup ---- Jan 11 00:32:09 volumio volumio[24892]: info: ------------------------------------------- Jan 11 00:32:09 volumio volumio[24892]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 00:32:09 volumio volumio[24892]: info: Adding plugin upnp to MyMusic Plugins Jan 11 00:32:09 volumio volumio[24892]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 00:32:09 volumio volumio[24892]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 00:32:09 volumio volumio[24892]: info: Loading plugins from folder /data/plugins/ Jan 11 00:32:09 volumio volumio[24892]: info: Loading plugin "system"... Jan 11 00:32:09 volumio volumio[24892]: info: Loading plugin "appearance"... Jan 11 00:32:11 volumio volumio[24892]: info: Loading plugin "network"... Jan 11 00:32:11 volumio volumio[24892]: info: Refreshing Cached IP Addresses Jan 11 00:32:11 volumio sudo[24946]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 00:32:11 volumio sudo[24946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:11 volumio sudo[24948]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 00:32:11 volumio sudo[24948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:11 volumio sudo[24946]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:11 volumio sudo[24948]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:11 volumio volumio[24892]: info: Loading plugin "services"... Jan 11 00:32:11 volumio volumio[24892]: info: Loading plugin "alsa_controller"... Jan 11 00:32:11 volumio sudo[24957]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 00:32:11 volumio sudo[24957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:11 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 00:32:11 volumio volumio[24892]: info: Loading plugin "wizard"... Jan 11 00:32:11 volumio volumio[24892]: info: Loading plugin "networkfs"... Jan 11 00:32:11 volumio volumio[24892]: info: Starting Udev Watcher for removable devices Jan 11 00:32:11 volumio volumio[24892]: info: Ignoring mount for partition: boot Jan 11 00:32:11 volumio volumio[24892]: info: Ignoring mount for partition: volumio Jan 11 00:32:11 volumio volumio[24892]: info: Ignoring mount for partition: volumio_data Jan 11 00:32:11 volumio volumio[24892]: info: Mounting Device Wikipedia Jan 11 00:32:11 volumio sudo[24985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 11 00:32:11 volumio sudo[24985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:11 volumio sudo[24985]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:11 volumio volumio[24892]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 11 00:32:11 volumio volumio[24892]: dmesg(1) may have more information after failed mount system call. Jan 11 00:32:11 volumio volumio[24892]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 11 00:32:11 volumio volumio[24892]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 11 00:32:11 volumio volumio[24892]: dmesg(1) may have more information after failed mount system call. Jan 11 00:32:11 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 00:32:11 volumio volumio[24892]: info: Loading plugin "volumio_command_line_client"... Jan 11 00:32:11 volumio volumio[24892]: info: Loading plugin "upnp"... Jan 11 00:32:11 volumio volumio[24892]: info: [1768113131439] Starting Upmpd Daemon Jan 11 00:32:11 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 00:32:11 volumio volumio[24892]: info: Loading plugin "my_music"... Jan 11 00:32:11 volumio volumio[24892]: info: Loading plugin "mpd"... Jan 11 00:32:11 volumio sudo[24957]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:11 volumio volumio-remote-updater[14193]: [2026-01-11 00:32:11] [connect] Successful connection Jan 11 00:32:12 volumio volumio[24892]: info: Loading plugin "upnp_browser"... Jan 11 00:32:12 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 00:32:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99. Jan 11 00:32:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:12 volumio go-librespot[24988]: go-librespot daemon starting... Jan 11 00:32:12 volumio go-librespot[24989]: time="2026-01-11T00:32:12-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:12 volumio go-librespot[24989]: time="2026-01-11T00:32:12-06:00" level=debug msg="app state loaded" Jan 11 00:32:12 volumio go-librespot[24989]: time="2026-01-11T00:32:12-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:12 volumio go-librespot[24989]: time="2026-01-11T00:32:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:12 volumio go-librespot[24989]: time="2026-01-11T00:32: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 00:32:12 volumio go-librespot[24989]: time="2026-01-11T00:32:12-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 00:32:12 volumio go-librespot[24989]: time="2026-01-11T00:32:12-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 00:32:12 volumio go-librespot[24989]: time="2026-01-11T00:32:12-06:00" level=info msg="zeroconf server listening on port 43325" Jan 11 00:32:13 volumio go-librespot[24989]: time="2026-01-11T00:32:13-06:00" level=debug msg="obtained new client token: AACBL2RthW5t4fLcIBsrK81/OQh1dx35xKvcyLaZ/aJBXZlDXk3NSPdy/ZSMW2q7GXYrNS1Rey0tatoR72U+pkPOkp3qWkLaUKV+wUi8iIMIs1DbWdyb8MjQUNledvMwJ1rwbPlhuKKsMu9w01A8NmeiqqHlxS494yvq8ok9FPNXWFAjSyz5vScKGs3GtLKcdERhJgQ6H33qPFphMMAduBX/wTgBQ6+OgexVEgktU9q+zqztzMrX4rY=" Jan 11 00:32:13 volumio go-librespot[24989]: time="2026-01-11T00:32:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:13 volumio go-librespot[24989]: time="2026-01-11T00:32:13-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:13 volumio go-librespot[24989]: time="2026-01-11T00:32:13-06:00" level=debug msg="completed challenge" Jan 11 00:32:13 volumio go-librespot[24989]: time="2026-01-11T00:32:13-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:13 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.65.239 Jan 11 00:32:13 volumio avahi-daemon[664]: Registering new address record for 169.254.65.239 on eth0.IPv4. Jan 11 00:32:13 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:32:13 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:13 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:13 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:14 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.65.239 Jan 11 00:32:14 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.65.239 Jan 11 00:32:14 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.65.239 Jan 11 00:32:14 volumio avahi-daemon[664]: Withdrawing address record for 169.254.65.239 on eth0. Jan 11 00:32:14 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:32:14 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:14 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:14 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:14 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:32:14 volumio volumio[24892]: info: Loading plugin "alarm-clock"... Jan 11 00:32:14 volumio volumio[24892]: info: Loading plugin "airplay_emulation"... Jan 11 00:32:14 volumio volumio[24892]: info: Starting Shairport Sync Jan 11 00:32:14 volumio volumio[24892]: info: Loading plugin "last_100"... Jan 11 00:32:14 volumio volumio[24892]: info: Loading plugin "webradio"... Jan 11 00:32:15 volumio volumio[24892]: info: Loading plugin "i2s_dacs"... Jan 11 00:32:15 volumio volumio[24892]: info: I2S DAC not set, start Auto-detection Jan 11 00:32:15 volumio volumio[24892]: info: Loading plugin "volumiodiscovery"... Jan 11 00:32:15 volumio volumio[24892]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 00:32:15 volumio volumio[24892]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 00:32:15 volumio volumio[24892]: *** WARNING *** For more information see Jan 11 00:32:15 volumio volumio[24892]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 00:32:15 volumio volumio[24892]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 00:32:15 volumio volumio[24892]: *** WARNING *** For more information see Jan 11 00:32:15 volumio node[24892]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 00:32:15 volumio node[24892]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 00:32:15 volumio node[24892]: *** WARNING *** For more information see Jan 11 00:32:15 volumio node[24892]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 00:32:15 volumio node[24892]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 00:32:15 volumio node[24892]: *** WARNING *** For more information see Jan 11 00:32:15 volumio volumio[24892]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 00:32:15 volumio volumio[24892]: info: Discovery: Started advertising with name: Volumio Jan 11 00:32:15 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 00:32:15 volumio volumio[24892]: info: Loading plugin "bandcamp"... Jan 11 00:32:16 volumio volumio[24892]: info: Plugin calmradio is not enabled Jan 11 00:32:16 volumio volumio[24892]: info: Loading plugin "soundcloud"... Jan 11 00:32:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 100. Jan 11 00:32:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:16 volumio go-librespot[25030]: go-librespot daemon starting... Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=debug msg="app state loaded" Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=info msg="zeroconf server listening on port 36967" Jan 11 00:32:16 volumio volumio[24892]: info: Loading plugin "spop"... Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=debug msg="obtained new client token: AAD3+rMU43TdfTv8pH24hnyWxSAe4YSV/V9J9zBC/h/nqWJMHis1EpbzdwB7e/2wbUEY8U/qOeUSvr39uAcFqT3Tpu7GAb8o6QznuzKQ0SUBg/jiyJon1Ka4mjRyLnOPnnIiOJ4E16c4K265wZUuvrRH3+s6p6yb23XGEBKPFJtMArBJcPaSpYzXVavv/m70ce8jaU7YdrtqbN85duY3EpxWispESGLJeF93ISfcF6ws+PuoVAm2ey+b7Q==" Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:16 volumio go-librespot[25031]: time="2026-01-11T00:32:16-06:00" level=debug msg="completed challenge" Jan 11 00:32:17 volumio go-librespot[25031]: time="2026-01-11T00:32:17-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:17 volumio volumio[24892]: info: Loading plugin "squeezelite_mc"... Jan 11 00:32:18 volumio volumio[24892]: info: Loading plugin "youtube2"... Jan 11 00:32:18 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 00:32:19 volumio volumio[24892]: info: Loading plugin "ytcr"... Jan 11 00:32:20 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.19.20 Jan 11 00:32:20 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:32:20 volumio avahi-daemon[664]: Registering new address record for 169.254.19.20 on eth0.IPv4. Jan 11 00:32:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 101. Jan 11 00:32:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:20 volumio go-librespot[25058]: go-librespot daemon starting... Jan 11 00:32:20 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:20 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:20 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:20 volumio go-librespot[25059]: time="2026-01-11T00:32:20-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:20 volumio go-librespot[25059]: time="2026-01-11T00:32:20-06:00" level=debug msg="app state loaded" Jan 11 00:32:20 volumio go-librespot[25059]: time="2026-01-11T00:32:20-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:20 volumio go-librespot[25059]: time="2026-01-11T00:32:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:20 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 00:32:20 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.19.20 Jan 11 00:32:20 volumio go-librespot[25059]: time="2026-01-11T00:32:20-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:32:20 volumio go-librespot[25059]: time="2026-01-11T00:32:20-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:32:20 volumio go-librespot[25059]: time="2026-01-11T00:32:20-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:32:20 volumio go-librespot[25059]: time="2026-01-11T00:32:20-06:00" level=info msg="zeroconf server listening on port 39177" Jan 11 00:32:20 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.19.20 Jan 11 00:32:20 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.19.20 Jan 11 00:32:20 volumio avahi-daemon[664]: Withdrawing address record for 169.254.19.20 on eth0. Jan 11 00:32:20 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:32:20 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:20 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:20 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:20 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:32:20 volumio go-librespot[25059]: time="2026-01-11T00:32:20-06:00" level=debug msg="obtained new client token: AADE5hoHQzLa8G5z7St5bNE/SOR7rMEqr4NF60plVRTkNZw2vEaljI0pGW8+M3OE3dLxy++Je+OlJL52ERWglDCpJzarS0esMcgjjoM3q1kYK3e3nITdKnG/3n3rf/70HO+2cry7qe7R7p+go57qEozIGB3BZN38AyDA0G52s697/TQXkroqQ0HFtBlZm4edhIINFR6v9mFeH7q2N7yd08d+JvQ1BH7Xznv/xamEn6QBc4B3BARhVVIGww==" Jan 11 00:32:21 volumio go-librespot[25059]: time="2026-01-11T00:32:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:21 volumio go-librespot[25059]: time="2026-01-11T00:32:21-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:21 volumio go-librespot[25059]: time="2026-01-11T00:32:21-06:00" level=debug msg="completed challenge" Jan 11 00:32:21 volumio go-librespot[25059]: time="2026-01-11T00:32:21-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:21 volumio volumio[24892]: info: Loading plugin "ytmusic"... Jan 11 00:32:22 volumio volumio[24892]: info: Plugin now_playing is not enabled Jan 11 00:32:22 volumio volumio[24892]: info: Loading plugin "outputs"... Jan 11 00:32:22 volumio volumio[24892]: info: Loading plugin "albumart"... Jan 11 00:32:22 volumio volumio[24892]: info: Plugin example_plugin is not enabled Jan 11 00:32:22 volumio volumio[24892]: info: Loading plugin "inputs"... Jan 11 00:32:22 volumio volumio[24892]: info: Loading plugin "updater_comm"... Jan 11 00:32:22 volumio volumio[24892]: info: Plugin mpdemulation is not enabled Jan 11 00:32:22 volumio volumio[24892]: info: Loading plugin "rest_api"... Jan 11 00:32:22 volumio volumio[24892]: info: Loading plugin "websocket"... Jan 11 00:32:22 volumio volumio[24892]: info: Starting Socket.io Server version 1.7.4 Jan 11 00:32:22 volumio volumio[24892]: info: Plugin fusiondsp is not enabled Jan 11 00:32:22 volumio volumio[24892]: info: Plugin mpdoutput is not enabled Jan 11 00:32:22 volumio volumio[24892]: info: Plugin RoonBridge is not enabled Jan 11 00:32:22 volumio volumio[24892]: info: Loading plugin "podcast"... Jan 11 00:32:22 volumio volumio[24892]: info: ControllerPodcast::constructor Jan 11 00:32:23 volumio volumio[24892]: info: Loading plugin "volusonic"... Jan 11 00:32:23 volumio volumio[25096]: Forking 3 albumart workers Jan 11 00:32:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 102. Jan 11 00:32:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:24 volumio volumio-remote-updater[14193]: [2026-01-11 00:32:24] [connect] Successful connection Jan 11 00:32:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:24 volumio go-librespot[25136]: go-librespot daemon starting... Jan 11 00:32:24 volumio go-librespot[25137]: time="2026-01-11T00:32:24-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:24 volumio go-librespot[25137]: time="2026-01-11T00:32:24-06:00" level=debug msg="app state loaded" Jan 11 00:32:24 volumio go-librespot[25137]: time="2026-01-11T00:32:24-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:24 volumio go-librespot[25137]: time="2026-01-11T00:32:24-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:24 volumio go-librespot[25137]: time="2026-01-11T00:32:24-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:32:24 volumio go-librespot[25137]: time="2026-01-11T00:32:24-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:32:24 volumio go-librespot[25137]: time="2026-01-11T00:32:24-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:32:24 volumio go-librespot[25137]: time="2026-01-11T00:32:24-06:00" level=info msg="zeroconf server listening on port 45277" Jan 11 00:32:25 volumio go-librespot[25137]: time="2026-01-11T00:32:25-06:00" level=debug msg="obtained new client token: AAD/EXt8AKL7/pOZLDnNV2FtFIfVdpMyJW7iBPYdloHENERsmetI6yzE1eUBJkOEfXTFRJHdxHZqnrAZJgTuW23NpxLRpMolRqYKrgiY/jz1b5nqT6up2NO9jA2aJT00CeM2/v8EYp4/abcu/+BuP1DRItOQzUMQMc2H7a3qoos96A+9DIQpKBCEtHBO0Ryobl9fQNEy65r8E65KcP0AhheUqbbguiAmPOEbnYrfkODqWcMLAIbe2U4=" Jan 11 00:32:25 volumio go-librespot[25137]: time="2026-01-11T00:32:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:25 volumio go-librespot[25137]: time="2026-01-11T00:32:25-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:25 volumio go-librespot[25137]: time="2026-01-11T00:32:25-06:00" level=debug msg="completed challenge" Jan 11 00:32:25 volumio go-librespot[25137]: time="2026-01-11T00:32:25-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:25 volumio volumio[24892]: info: Applying required configuration parameters for plugin volusonic Jan 11 00:32:25 volumio volumio[24892]: info: Loading plugin "backup_restore"... Jan 11 00:32:26 volumio volumio[25108]: Starting albumart workers Jan 11 00:32:26 volumio volumio[25106]: Starting albumart workers Jan 11 00:32:26 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.135.33 Jan 11 00:32:26 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:32:26 volumio avahi-daemon[664]: Registering new address record for 169.254.135.33 on eth0.IPv4. Jan 11 00:32:26 volumio volumio[25107]: Starting albumart workers Jan 11 00:32:26 volumio volumio[24892]: info: Applying required configuration parameters for plugin backup_restore Jan 11 00:32:26 volumio volumio[24892]: info: Plugin rpi_eeprom_config is not enabled Jan 11 00:32:26 volumio volumio[24892]: info: Plugin rpi_eeprom_updater is not enabled Jan 11 00:32:26 volumio volumio[24892]: info: Loading plugin "scheduledrestart"... Jan 11 00:32:26 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:26 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:26 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:26 volumio volumio[24892]: info: Applying required configuration parameters for plugin scheduledrestart Jan 11 00:32:26 volumio volumio[24892]: info: Plugin Bluetoothremote is not enabled Jan 11 00:32:26 volumio volumio[24892]: info: Plugin music_services_shield is not enabled Jan 11 00:32:26 volumio volumio[24892]: info: Loading plugin "Systeminfo"... Jan 11 00:32:26 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.135.33 Jan 11 00:32:27 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.135.33 Jan 11 00:32:27 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.135.33 Jan 11 00:32:27 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:32:27 volumio avahi-daemon[664]: Withdrawing address record for 169.254.135.33 on eth0. Jan 11 00:32:27 volumio volumio[24892]: info: Plugin peppymeterbasic is not enabled Jan 11 00:32:27 volumio volumio[24892]: info: Loading plugin "peppyspectrum"... Jan 11 00:32:27 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:27 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:32:27 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:27 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:27 volumio volumio[24892]: info: Loading i18n strings for locale en Jan 11 00:32:27 volumio volumio[24892]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 00:32:27 volumio volumio[24892]: Updating browse sources language Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::initPlayerControls Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 00:32:27 volumio volumio[24892]: Express server listening on port 3000 Jan 11 00:32:27 volumio volumio[24892]: [Metrics] WebUI: 19s 222.24ms Jan 11 00:32:27 volumio volumio[24892]: info: CoreStateMachine::resetVolumioState Jan 11 00:32:27 volumio volumio[24892]: info: CoreStateMachine::getcurrentVolume Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:32:27 volumio sudo[25199]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 00:32:27 volumio sudo[25199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:27 volumio sudo[25199]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:27 volumio sudo[25201]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 00:32:27 volumio sudo[25201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:27 volumio sudo[25201]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:27 volumio volumio[24892]: info: Volumio Network Manager: Network status updated: 1 Jan 11 00:32:27 volumio volumio[24892]: info: VolumeController:: Volume=100 Mute =false Jan 11 00:32:27 volumio volumio[24892]: info: CoreStateMachine::pushState Jan 11 00:32:27 volumio volumio[24892]: info: CorePlayQueue::getTrack 0 Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::volumioPushState Jan 11 00:32:27 volumio volumio[24892]: info: CoreStateMachine::updateTrackBlock Jan 11 00:32:27 volumio volumio[24892]: info: CorePlayQueue::getTrackBlock Jan 11 00:32:27 volumio volumio[24892]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 00:32:27 volumio volumio-remote-updater[14193]: [2026-01-11 00:32:27] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768113144 101 Jan 11 00:32:27 volumio volumio[24892]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 11 00:32:28 volumio volumio[24892]: info: Reloading queue from file Jan 11 00:32:28 volumio volumio[24892]: info: CoreStateMachine::setRepeat null single undefined Jan 11 00:32:28 volumio volumio[24892]: info: CoreStateMachine::pushState Jan 11 00:32:28 volumio volumio[24892]: info: CorePlayQueue::getTrack 0 Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::volumioPushState Jan 11 00:32:28 volumio volumio[24892]: info: CoreStateMachine::setRandom null Jan 11 00:32:28 volumio volumio[24892]: info: CoreStateMachine::pushState Jan 11 00:32:28 volumio volumio[24892]: info: CorePlayQueue::getTrack 0 Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::volumioPushState Jan 11 00:32:28 volumio volumio[24892]: info: Setting Device type: Raspberry PI Jan 11 00:32:28 volumio volumio[24892]: info: VolumeController:: Volume=100 Mute =false Jan 11 00:32:28 volumio volumio[24892]: info: CoreStateMachine::pushState Jan 11 00:32:28 volumio volumio[24892]: info: CorePlayQueue::getTrack 0 Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::volumioPushState Jan 11 00:32:28 volumio volumio[24892]: info: Completed loading Core Plugins Jan 11 00:32:28 volumio volumio[24892]: info: Preparing to generate the ALSA configuration file Jan 11 00:32:28 volumio sudo[25215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 11 00:32:28 volumio sudo[25215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:28 volumio volumio[24892]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 11 00:32:28 volumio volumio[24892]: info: Discovery: Found device Volumio Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::volumioGetState Jan 11 00:32:28 volumio volumio[24892]: info: CorePlayQueue::getTrack 0 Jan 11 00:32:28 volumio volumio[24892]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 00:32:28 volumio volumio[24892]: info: Reading ALSA contributions from plugins. Jan 11 00:32:28 volumio volumio[24892]: info: Asound.conf file unchanged, so no further update is needed Jan 11 00:32:28 volumio volumio[24892]: info: Output device has changed, restarting MPD Jan 11 00:32:28 volumio sudo[25215]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:28 volumio volumio[24892]: info: Output device has changed, restarting Shairport Sync Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:32:28 volumio sudo[25218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 00:32:28 volumio sudo[25218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:28 volumio sudo[25218]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:28 volumio volumio[24892]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 00:32:28 volumio sudo[25220]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 00:32:28 volumio volumio[24892]: info: ___________ START PLUGINS ___________ Jan 11 00:32:28 volumio sudo[25220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:28 volumio volumio[24892]: info: ControllerMpd::onStart: Initializing MPD Jan 11 00:32:28 volumio volumio[24892]: info: Creating MPD Configuration file Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:32:28 volumio volumio[24892]: info: [1768113148267] CoreMusicLibrary::Adding element Media Servers Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:28 volumio sudo[25228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 00:32:28 volumio sudo[25228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:28 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 11 00:32:28 volumio sudo[25228]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:28 volumio sudo[25230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 00:32:28 volumio sudo[25230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:32:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 103. Jan 11 00:32:28 volumio volumio[24892]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:32:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:28 volumio volumio[24892]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:32:28 volumio volumio[24892]: info: [1768113148394] CoreMusicLibrary::Adding element Last_100 Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:32:28 volumio volumio[24892]: info: [1768113148400] CoreMusicLibrary::Adding element Webradio Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 00:32:28 volumio volumio[24892]: info: Initializing BBC Radios Jan 11 00:32:28 volumio go-librespot[25241]: go-librespot daemon starting... Jan 11 00:32:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:28 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 11 00:32:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 11 00:32:28 volumio systemd[1]: mpd.service: Consumed 6.472s CPU time. Jan 11 00:32:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 11 00:32:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 11 00:32:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 11 00:32:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:32:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 11 00:32:28 volumio go-librespot[25249]: time="2026-01-11T00:32:28-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:28 volumio go-librespot[25249]: time="2026-01-11T00:32:28-06:00" level=debug msg="app state loaded" Jan 11 00:32:28 volumio go-librespot[25249]: time="2026-01-11T00:32:28-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:28 volumio go-librespot[25249]: time="2026-01-11T00:32:28-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:32:28 volumio volumio[24892]: info: [1768113148548] CoreMusicLibrary::Adding element Bandcamp Discover Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:28 volumio volumio[24892]: Cannot find translation for source Bandcamp Discover Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:32:28 volumio volumio[24892]: info: [1768113148575] CoreMusicLibrary::Adding element SoundCloud Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:28 volumio volumio[24892]: Cannot find translation for source Bandcamp Discover Jan 11 00:32:28 volumio volumio[24892]: Cannot find translation for source SoundCloud Jan 11 00:32:28 volumio volumio[24892]: info: Creating Spotify config file Jan 11 00:32:28 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:28 volumio go-librespot[25249]: time="2026-01-11T00:32:28-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 00:32:28 volumio go-librespot[25249]: time="2026-01-11T00:32:28-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 00:32:28 volumio go-librespot[25249]: time="2026-01-11T00:32:28-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 00:32:28 volumio go-librespot[25249]: time="2026-01-11T00:32:28-06:00" level=info msg="zeroconf server listening on port 43565" Jan 11 00:32:29 volumio sudo[25262]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 00:32:29 volumio sudo[25262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 11 00:32:29 volumio sudo[25262]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:29 volumio go-librespot[25249]: time="2026-01-11T00:32:29-06:00" level=debug msg="obtained new client token: AACvdVP+OU1EmiYeiarF7aI6rpJlK65fgkPVVQFfxYBWs8lSaBlp1YzulAZes6wTxrXTjA1lakxzKKUs+rym+moKiRKCyqz/pP+ffp+0QPBYuH1n4xbQWcSY4t5gLW7IzmpCTgg8xdMJ6ZjGvJYJ6woNhSlzesuH3UWh/DAJ2MiWW79JZMuYu0RrvoJZ5Tv+cSLIVe9LMFt/6wp0n/jPg4hYS7wOulK+mdxViXMrgWoMrKLG4fOO0u8=" Jan 11 00:32:29 volumio go-librespot[25249]: time="2026-01-11T00:32:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:29 volumio go-librespot[25249]: time="2026-01-11T00:32:29-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:29 volumio go-librespot[25249]: time="2026-01-11T00:32:29-06:00" level=debug msg="completed challenge" Jan 11 00:32:29 volumio go-librespot[25249]: time="2026-01-11T00:32:29-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:29 volumio volumio[24892]: info: [squeezelite_mc] Starting proxy server... Jan 11 00:32:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:32:29 volumio volumio[24892]: info: [1768113149353] CoreMusicLibrary::Adding element YouTube2 Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Bandcamp Discover Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source SoundCloud Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube2 Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:32:29 volumio volumio[24892]: info: [1768113149391] CoreMusicLibrary::Adding element YouTube Music Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Bandcamp Discover Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source SoundCloud Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube2 Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube Music Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:32:29 volumio volumio[24892]: info: [1768113149411] CoreMusicLibrary::Adding element Podcast Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Bandcamp Discover Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source SoundCloud Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube2 Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube Music Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Podcast Jan 11 00:32:29 volumio volumio[24892]: info: Loading i18n strings for locale en Jan 11 00:32:29 volumio volumio[24892]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 00:32:29 volumio volumio[24892]: Updating browse sources language Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Bandcamp Discover Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source SoundCloud Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube2 Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube Music Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Podcast Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Bandcamp Discover Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source SoundCloud Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube2 Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube Music Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Podcast Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:32:29 volumio volumio[24892]: info: [1768113149496] CoreMusicLibrary::Adding element Volusonic Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Bandcamp Discover Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source SoundCloud Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube2 Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source YouTube Music Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Podcast Jan 11 00:32:29 volumio volumio[24892]: Cannot find translation for source Volusonic Jan 11 00:32:29 volumio volumio[24892]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 00:32:29 volumio volumio[24892]: info: Volumio Calling Home Jan 11 00:32:29 volumio volumio[24892]: info: [squeezelite_mc] Proxy server started on port 33371 Jan 11 00:32:29 volumio volumio[24892]: info: Preparing to generate the ALSA configuration file Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 00:32:29 volumio volumio[24892]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 11 00:32:29 volumio volumio[24892]: info: Discovery: Found device Volumio Jan 11 00:32:29 volumio volumio[24892]: info: CoreCommandRouter::volumioGetState Jan 11 00:32:29 volumio volumio[24892]: info: CorePlayQueue::getTrack 0 Jan 11 00:32:30 volumio volumio[24892]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 00:32:30 volumio volumio[24892]: info: Reading ALSA contributions from plugins. Jan 11 00:32:30 volumio volumio[24892]: info: MPD Permissions set Jan 11 00:32:30 volumio volumio[24892]: info: MPD Permissions set Jan 11 00:32:30 volumio volumio[24892]: info: Upmpdcli Daemon Started Jan 11 00:32:30 volumio volumio[24892]: info: Spotify config file written Jan 11 00:32:30 volumio sudo[25275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 11 00:32:30 volumio sudo[25275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:30 volumio volumio[24892]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 00:32:30 volumio volumio[24892]: info: VolumeController:: Volume=100 Mute =false Jan 11 00:32:30 volumio volumio[24892]: info: CoreStateMachine::pushState Jan 11 00:32:30 volumio volumio[24892]: info: CorePlayQueue::getTrack 0 Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::volumioPushState Jan 11 00:32:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:30 volumio go-librespot[25277]: go-librespot daemon starting... Jan 11 00:32:30 volumio volumio[24892]: info: [squeezelite_mc] Server discovery started Jan 11 00:32:30 volumio volumio[24892]: info: [squeezelite_mc] Player finder started Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 11 00:32:30 volumio sudo[25275]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio go-librespot[25278]: time="2026-01-11T00:32:30-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:30 volumio go-librespot[25278]: time="2026-01-11T00:32:30-06:00" level=debug msg="app state loaded" Jan 11 00:32:30 volumio go-librespot[25278]: time="2026-01-11T00:32:30-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:30 volumio go-librespot[25278]: time="2026-01-11T00:32:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:30 volumio volumio[24892]: info: No need to fix Spotify hosts Jan 11 00:32:30 volumio volumio[24892]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 11 00:32:30 volumio volumio[24892]: info: Volumio called home Jan 11 00:32:30 volumio go-librespot[25278]: time="2026-01-11T00:32: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]" Jan 11 00:32:30 volumio go-librespot[25278]: time="2026-01-11T00:32: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]" Jan 11 00:32:30 volumio go-librespot[25278]: time="2026-01-11T00:32: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]" Jan 11 00:32:30 volumio go-librespot[25278]: time="2026-01-11T00:32:30-06:00" level=info msg="zeroconf server listening on port 37195" Jan 11 00:32:30 volumio volumio[24892]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 11 00:32:30 volumio volumio[24892]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 11 00:32:30 volumio volumio[24892]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Jan 11 00:32:31 volumio volumio[24892]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 00:32:31 volumio volumio[24892]: SPOTIFY: BQBHF5Q8juc5U_p_p7kk9mqNIfI5EVQeZ5yN0HD1DMyKAk-lX--kYF-Mg_kuFk6TJ13NOopuPTn3AuAvXvBrh2gm9f0jvrhu9KWbaziJoQVyXoO5e2l5wzvdNX1U_HyhsaBz6tl7dnM92mALPTbjF7VtzESXyAZRUn6ASKz3pOUHjxrR6YbQwIHahj9r-TKuWwAzRT_v0Pos_S-AoS1wnx-tLUtHuA22qurLUIg Jan 11 00:32:31 volumio volumio[24892]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 00:32:31 volumio volumio[24892]: info: New Spotify access token = BQBHF5Q8juc5U_p_p7kk9mqNIfI5EVQeZ5yN0HD1DMyKAk-lX--kYF-Mg_kuFk6TJ13NOopuPTn3AuAvXvBrh2gm9f0jvrhu9KWbaziJoQVyXoO5e2l5wzvdNX1U_HyhsaBz6tl7dnM92mALPTbjF7VtzESXyAZRUn6ASKz3pOUHjxrR6YbQwIHahj9r-TKuWwAzRT_v0Pos_S-AoS1wnx-tLUtHuA22qurLUIg Jan 11 00:32:31 volumio volumio[24892]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 11 00:32:31 volumio go-librespot[25278]: time="2026-01-11T00:32:31-06:00" level=debug msg="obtained new client token: AADhkh3Niop8Z3XWhMaG1W/tL6LzUivFxw8wF3rO8Qe4T9HVK5ZzHFxkpGTyphcM5y63BCbjCwOY8SUYKTDayM3/M4UVqn0dK2dHbUeJZd+VBtMbSEDLucKWR1e68UGnSTPZ4DhKoKVa8amu1xVR4kU66fxoMh4NByb3ysVBVj3ksS8CnzmE5HRLtxmqw9npyqtn2LrYqPEuqAHM/bEneaJODLT03CSqDdQVwoOJdRi4X7FpHjyzvpk=" Jan 11 00:32:31 volumio volumio[24892]: info: Starting Shairport Sync Jan 11 00:32:31 volumio go-librespot[25278]: time="2026-01-11T00:32:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:31 volumio volumio[24892]: info: Starting Shairport Sync Jan 11 00:32:31 volumio volumio[24892]: info: Starting Shairport Sync Jan 11 00:32:31 volumio go-librespot[25278]: time="2026-01-11T00:32:31-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:31 volumio go-librespot[25278]: time="2026-01-11T00:32:31-06:00" level=debug msg="completed challenge" Jan 11 00:32:31 volumio sudo[25301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 00:32:31 volumio sudo[25301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:31 volumio go-librespot[25278]: time="2026-01-11T00:32:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:31 volumio sudo[25303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 00:32:31 volumio sudo[25299]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Jan 11 00:32:31 volumio sudo[25299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:31 volumio sudo[25303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:31 volumio sudo[25299]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:31 volumio volumio[24892]: info: Asound.conf file unchanged, so no further update is needed Jan 11 00:32:31 volumio volumio[24892]: info: Output device has changed, restarting MPD Jan 11 00:32:31 volumio sudo[25305]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 00:32:31 volumio sudo[25305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:31 volumio volumio[24892]: info: Output device has changed, restarting Shairport Sync Jan 11 00:32:31 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:31 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:32:31 volumio sudo[25320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 00:32:31 volumio sudo[25320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:31 volumio sudo[25320]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:31 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 00:32:31 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 00:32:31 volumio sudo[25321]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 00:32:31 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 00:32:31 volumio systemd[1]: shairport-sync.service: Consumed 2.118s CPU time. Jan 11 00:32:31 volumio sudo[25321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:31 volumio volumio[24892]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 00:32:31 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 00:32:31 volumio sudo[25301]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:31 volumio sudo[25303]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:31 volumio sudo[25305]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:31 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 11 00:32:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 11 00:32:31 volumio systemd[1]: mpd.service: Consumed 3.042s CPU time. Jan 11 00:32:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 11 00:32:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 11 00:32:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 11 00:32:31 volumio volumio[24892]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 11 00:32:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 11 00:32:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 11 00:32:31 volumio sudo[25355]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 11 00:32:31 volumio sudo[25355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:31 volumio volumio[24892]: info: MPD Permissions set Jan 11 00:32:31 volumio volumio[24892]: info: Shairport-Sync Started Jan 11 00:32:31 volumio volumio[24892]: Error adding Membership: Error: addMembership EINVAL Jan 11 00:32:31 volumio volumio[24892]: info: Shairport-Sync Started Jan 11 00:32:31 volumio volumio[24892]: info: Shairport-Sync Started Jan 11 00:32:31 volumio sudo[25355]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:31 volumio volumio[24892]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 11 00:32:31 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:31 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:32 volumio volumio[24892]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Jan 11 00:32:32 volumio volumio[24892]: info: Spotify Successfully logged in Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:32:32 volumio volumio[24892]: info: [1768113152067] CoreMusicLibrary::Adding element Spotify Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:32:32 volumio volumio[24892]: Cannot find translation for source Bandcamp Discover Jan 11 00:32:32 volumio volumio[24892]: Cannot find translation for source SoundCloud Jan 11 00:32:32 volumio volumio[24892]: Cannot find translation for source YouTube2 Jan 11 00:32:32 volumio volumio[24892]: Cannot find translation for source YouTube Music Jan 11 00:32:32 volumio volumio[24892]: Cannot find translation for source Podcast Jan 11 00:32:32 volumio volumio[24892]: Cannot find translation for source Volusonic Jan 11 00:32:32 volumio volumio[24892]: Cannot find translation for source Spotify Jan 11 00:32:32 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.85.241 Jan 11 00:32:32 volumio avahi-daemon[664]: Registering new address record for 169.254.85.241 on eth0.IPv4. Jan 11 00:32:32 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:32:32 volumio volumio[24892]: info: CoreCommandRouter::volumioGetState Jan 11 00:32:32 volumio volumio[24892]: info: CorePlayQueue::getTrack 0 Jan 11 00:32:32 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:32 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:32 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:32 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.85.241 Jan 11 00:32:32 volumio sudo[25361]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 11 00:32:32 volumio sudo[25361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:32 volumio sudo[25357]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 00:32:32 volumio sudo[25357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 11 00:32:32 volumio volumio[24892]: info: Starting Shairport Sync Jan 11 00:32:32 volumio sudo[25357]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:32 volumio sudo[25361]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:32 volumio sudo[25386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 00:32:32 volumio sudo[25386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 00:32:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 00:32:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 00:32:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 00:32:32 volumio sudo[25386]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:32 volumio volumio[24892]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 11 00:32:32 volumio volumio[24892]: info: Shairport-Sync Started Jan 11 00:32:32 volumio sudo[25391]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 11 00:32:32 volumio sudo[25391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:32 volumio systemd[1]: Reloading. Jan 11 00:32:32 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.85.241 Jan 11 00:32:32 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.85.241 Jan 11 00:32:32 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:32:32 volumio avahi-daemon[664]: Withdrawing address record for 169.254.85.241 on eth0. Jan 11 00:32:33 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:32:33 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:33 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:33 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:32:33 volumio volumio[24892]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 00:32:33 volumio volumio[24892]: info: go-librespot daemon successfully initialized Jan 11 00:32:35 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 11 00:32:35 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 11 00:32:35 volumio sudo[25391]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 104. Jan 11 00:32:35 volumio volumio[24892]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:32:35 volumio sudo[25441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:32:35 volumio sudo[25441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:35 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:35 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:35 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:35 volumio go-librespot[25443]: go-librespot daemon starting... Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=debug msg="app state loaded" Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:36 volumio sudo[25441]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:36 volumio volumio[24892]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 11 00:32:36 volumio sudo[25451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 11 00:32:36 volumio sudo[25451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:36 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=info msg="zeroconf server listening on port 40191" Jan 11 00:32:36 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 11 00:32:36 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 11 00:32:36 volumio sudo[25451]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=debug msg="obtained new client token: AAADtVMFJBL2k/L9Z2gKHHbg086L8k/X060gMA8tWgvBybnNuqepwK5n1ccGDhjH5A9CGMpF9AtUO/8Cp/lgeCae/fPOOG7ivIWp/GqeImUb05y5bR6dC5bhAiZ7Wm/FOO96vMoYhU3LHmbZ58sygy99O+gdOadA2HEKnht9k60EN5KGgOZ8GpTyqw9NOolXf8m0b0uOtyXiVWKKAPMOOmfW4pdQGZn+jIeoXdC0HOPqnDO5BWNLIpGnJw==" Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=debug msg="completed challenge" Jan 11 00:32:36 volumio go-librespot[25444]: time="2026-01-11T00:32:36-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:36 volumio volumio[24892]: info: Initializing connection to go-librespot Websocket Jan 11 00:32:36 volumio volumio[24892]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 00:32:36 volumio volumio[24892]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:32:36 volumio sudo[25455]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:32:36 volumio sudo[25455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:36 volumio sudo[25455]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:36 volumio volumio[24892]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 11 00:32:37 volumio sudo[25459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 11 00:32:37 volumio sudo[25459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:37 volumio sudo[25459]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:37 volumio volumio[24892]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 11 00:32:37 volumio sudo[25462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 11 00:32:37 volumio sudo[25462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:37 volumio mpd[25387]: 2026-01-11T00:32:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 00:32:37 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 11 00:32:37 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 11 00:32:37 volumio sudo[25462]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:37 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 11 00:32:37 volumio sudo[25230]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:37 volumio sudo[25220]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:37 volumio sudo[25321]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:37 volumio volumio[24892]: error: MPD error: The expression evaluated to a falsy value: Jan 11 00:32:37 volumio volumio[24892]: assert.ok(self.idling) Jan 11 00:32:37 volumio volumio[24892]: error: The expression evaluated to a falsy value: Jan 11 00:32:37 volumio volumio[24892]: assert.ok(self.idling) Jan 11 00:32:37 volumio volumio[24892]: error: MPD error: The expression evaluated to a falsy value: Jan 11 00:32:37 volumio volumio[24892]: assert.ok(self.idling) Jan 11 00:32:37 volumio volumio[24892]: error: The expression evaluated to a falsy value: Jan 11 00:32:37 volumio volumio[24892]: assert.ok(self.idling) Jan 11 00:32:37 volumio volumio[24892]: info: MPD running with PID25387 Jan 11 00:32:37 volumio volumio[24892]: ,establishing connection Jan 11 00:32:37 volumio volumio[24892]: error: updateQueue error: null Jan 11 00:32:37 volumio volumio[24892]: error: updateQueue error: null Jan 11 00:32:37 volumio volumio[24892]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:32:37 volumio sudo[25473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:32:37 volumio sudo[25473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:37 volumio sudo[25473]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:38 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.94.3 Jan 11 00:32:38 volumio avahi-daemon[664]: Registering new address record for 169.254.94.3 on eth0.IPv4. Jan 11 00:32:38 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:32:38 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:38 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:38 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:38 volumio volumio[24892]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:32:38 volumio sudo[25492]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:32:38 volumio sudo[25492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:38 volumio sudo[25492]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:38 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.94.3 Jan 11 00:32:38 volumio volumio[24892]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:32:38 volumio sudo[25495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:32:38 volumio sudo[25495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:38 volumio sudo[25495]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:39 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.94.3 Jan 11 00:32:39 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.94.3 Jan 11 00:32:39 volumio avahi-daemon[664]: Withdrawing address record for 169.254.94.3 on eth0. Jan 11 00:32:39 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:32:39 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:32:39 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:39 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:39 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:39 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 00:32:39 volumio volumio[24892]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:32:39 volumio sudo[25518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:32:39 volumio sudo[25518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:39 volumio sudo[25518]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 105. Jan 11 00:32:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:39 volumio go-librespot[25520]: go-librespot daemon starting... Jan 11 00:32:39 volumio go-librespot[25521]: time="2026-01-11T00:32:39-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:39 volumio go-librespot[25521]: time="2026-01-11T00:32:39-06:00" level=debug msg="app state loaded" Jan 11 00:32:39 volumio go-librespot[25521]: time="2026-01-11T00:32:39-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:39 volumio go-librespot[25521]: time="2026-01-11T00:32:39-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:39 volumio volumio[24892]: info: Initializing connection to go-librespot Websocket Jan 11 00:32:39 volumio go-librespot[25521]: time="2026-01-11T00:32:39-06:00" level=debug msg="new websocket client" Jan 11 00:32:39 volumio volumio[24892]: info: Connection to go-librespot Websocket established Jan 11 00:32:39 volumio go-librespot[25521]: time="2026-01-11T00:32:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:32:39 volumio go-librespot[25521]: time="2026-01-11T00:32:39-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:32:39 volumio go-librespot[25521]: time="2026-01-11T00:32:39-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:32:39 volumio go-librespot[25521]: time="2026-01-11T00:32:39-06:00" level=info msg="zeroconf server listening on port 35207" Jan 11 00:32:40 volumio volumio[24892]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:32:40 volumio go-librespot[25521]: time="2026-01-11T00:32:40-06:00" level=debug msg="obtained new client token: AACs4q82nSG1ciISijAly6OiG1bpnH+SbsZ/FuOqvqlFEfAy6JPtgqZyi3jyY0cGXxzoNBpWBLM0l7LLJ9zNEJlIM81MusYcc/sXZHp75sqsAjenGGEPhsi1vBdAj56jj/mFR4tByEk1at6xFd3JD3NujyQYX5LLi2WijHg7mI7dBC71+od6OoqgK27CrLQNBGpv9jEr8azb2W+qDdCVaTwv5ee6Rie/zd7eHtbTiUOKpBYA8CFGKv8=" Jan 11 00:32:40 volumio sudo[25529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:32:40 volumio sudo[25529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:40 volumio go-librespot[25521]: time="2026-01-11T00:32:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:40 volumio sudo[25529]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:40 volumio volumio[24892]: info: Completed starting Core Plugins Jan 11 00:32:40 volumio volumio[24892]: info: ------------------------------------------- Jan 11 00:32:40 volumio volumio[24892]: info: ----- MyVolumio plugins startup ---- Jan 11 00:32:40 volumio volumio[24892]: info: ------------------------------------------- Jan 11 00:32:40 volumio volumio[24892]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 11 00:32:40 volumio go-librespot[25521]: time="2026-01-11T00:32:40-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:40 volumio go-librespot[25521]: time="2026-01-11T00:32:40-06:00" level=debug msg="completed challenge" Jan 11 00:32:40 volumio go-librespot[25521]: time="2026-01-11T00:32:40-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:40 volumio volumio[24892]: info: Connection to go-librespot Websocket closed Jan 11 00:32:40 volumio sudo[25532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 00:32:40 volumio sudo[25532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:40 volumio sudo[25534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 00:32:40 volumio sudo[25534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:40 volumio sudo[25537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 00:32:40 volumio sudo[25537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:40 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 11 00:32:40 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 11 00:32:40 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 11 00:32:40 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 11 00:32:40 volumio sudo[25537]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:40 volumio sudo[25532]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:40 volumio sudo[25534]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:40 volumio mpd_monitor.sh[25540]: MPD Monitor Service: Starting MPD Monitor Service Jan 11 00:32:40 volumio volumio[24892]: info: Successfully started MPD Monitor Jan 11 00:32:40 volumio volumio[24892]: info: Successfully started MPD Monitor Jan 11 00:32:40 volumio volumio[24892]: info: Successfully started MPD Monitor Jan 11 00:32:42 volumio volumio[24892]: info: Getting Spotify volume Jan 11 00:32:42 volumio volumio[24892]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 00:32:42 volumio volumio[24892]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 00:32:42 volumio volumio[24892]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 11 00:32:42 volumio volumio[24892]: errno: -111, Jan 11 00:32:42 volumio volumio[24892]: code: 'ECONNREFUSED', Jan 11 00:32:42 volumio volumio[24892]: syscall: 'connect', Jan 11 00:32:42 volumio volumio[24892]: address: '127.0.0.1', Jan 11 00:32:42 volumio volumio[24892]: port: 9879, Jan 11 00:32:42 volumio volumio[24892]: response: undefined Jan 11 00:32:42 volumio volumio[24892]: } Jan 11 00:32:42 volumio volumio[24892]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 00:32:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 106. Jan 11 00:32:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:43 volumio go-librespot[25571]: go-librespot daemon starting... Jan 11 00:32:43 volumio go-librespot[25572]: time="2026-01-11T00:32:43-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:43 volumio go-librespot[25572]: time="2026-01-11T00:32:43-06:00" level=debug msg="app state loaded" Jan 11 00:32:43 volumio go-librespot[25572]: time="2026-01-11T00:32:43-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:43 volumio go-librespot[25572]: time="2026-01-11T00:32:43-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:43 volumio sudo[25581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-11 00:31' Jan 11 00:32:43 volumio sudo[25581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:43 volumio go-librespot[25572]: time="2026-01-11T00:32: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]" Jan 11 00:32:43 volumio go-librespot[25572]: time="2026-01-11T00:32: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]" Jan 11 00:32:43 volumio go-librespot[25572]: time="2026-01-11T00:32: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]" Jan 11 00:32:43 volumio go-librespot[25572]: time="2026-01-11T00:32:43-06:00" level=info msg="zeroconf server listening on port 34403" Jan 11 00:32:43 volumio go-librespot[25572]: time="2026-01-11T00:32:43-06:00" level=debug msg="obtained new client token: AACOTeLJn40RiHuea6pD88vx0kRb7+jDUqHtTIyrfJOJnRGmP/N3hK92FMJILt6AcFp1y/+uytNOLZH9M3Q8NiUhcZldGTFcG0wnuUHqtLaODe+qbcjcgXcfirlGe7qJcd7CCLM5D1vPMbxDxDFPd7XmFAJy9k7ViVHfWAjJrPIJK6nPkZPdDEMAFtjtjuZdE13w7KtXuSUqTbAEgoMVmpBL3HC27tLD31zU1vpsw19XlUuco73t4jtitQ==" Jan 11 00:32:43 volumio go-librespot[25572]: time="2026-01-11T00:32:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:44 volumio go-librespot[25572]: time="2026-01-11T00:32:43-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:44 volumio go-librespot[25572]: time="2026-01-11T00:32:44-06:00" level=debug msg="completed challenge" Jan 11 00:32:44 volumio go-librespot[25572]: time="2026-01-11T00:32:44-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:44 volumio sudo[25581]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:44 volumio volumio-remote-updater[14193]: [2026-01-11 00:32:44] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 11 00:32:44 volumio volumio-remote-updater[14193]: [2026-01-11 00:32:44] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 11 00:32:44 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:44 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 00:32:44 volumio systemd[1]: volumio.service: Consumed 47.011s CPU time. Jan 11 00:32:44 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 11 00:32:44 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.20.131 Jan 11 00:32:44 volumio avahi-daemon[664]: Registering new address record for 169.254.20.131 on eth0.IPv4. Jan 11 00:32:44 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 11 00:32:44 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:32:44 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 18871. Jan 11 00:32:44 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 11 00:32:44 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 11 00:32:44 volumio systemd[1]: volumio.service: Consumed 47.011s CPU time. Jan 11 00:32:44 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 11 00:32:44 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:44 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:44 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:44 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 11 00:32:44 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.20.131 Jan 11 00:32:45 volumio ntpd[872]: IO: Listen normally on 12097 eth0 169.254.20.131:123 Jan 11 00:32:45 volumio ntpd[872]: IO: new interface(s) found: waking up resolver Jan 11 00:32:45 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.20.131 Jan 11 00:32:45 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.20.131 Jan 11 00:32:45 volumio avahi-daemon[664]: Withdrawing address record for 169.254.20.131 on eth0. Jan 11 00:32:45 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:32:45 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:45 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:45 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:45 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:32:46 volumio volumio[25610]: info: ------------------------------------------- Jan 11 00:32:46 volumio volumio[25610]: info: ----- Volumio3 ---- Jan 11 00:32:46 volumio volumio[25610]: info: ------------------------------------------- Jan 11 00:32:46 volumio volumio[25610]: info: ----- System startup ---- Jan 11 00:32:46 volumio volumio[25610]: info: ------------------------------------------- Jan 11 00:32:47 volumio volumio[25610]: info: MYVOLUMIO Environment detected Jan 11 00:32:47 volumio volumio[25610]: info: Plugin folders cleanup Jan 11 00:32:47 volumio volumio[25610]: info: Scanning into folder /volumio/app/plugins/ Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category audio_interface Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category miscellanea Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category music_service Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category plugins.json Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category system_controller Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category user_interface Jan 11 00:32:47 volumio volumio[25610]: info: Scanning into folder /data/plugins/ Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category audio_interface Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category music_service Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category system_controller Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category system_hardware Jan 11 00:32:47 volumio volumio[25610]: info: Scanning category user_interface Jan 11 00:32:47 volumio volumio[25610]: info: Plugin folders cleanup completed Jan 11 00:32:47 volumio volumio[25610]: info: ------------------------------------------- Jan 11 00:32:47 volumio volumio[25610]: info: ----- Core plugins startup ---- Jan 11 00:32:47 volumio volumio[25610]: info: ------------------------------------------- Jan 11 00:32:47 volumio volumio[25610]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 00:32:47 volumio volumio[25610]: info: Adding plugin upnp to MyMusic Plugins Jan 11 00:32:47 volumio volumio[25610]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 00:32:47 volumio volumio[25610]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 00:32:47 volumio volumio[25610]: info: Loading plugins from folder /data/plugins/ Jan 11 00:32:47 volumio volumio[25610]: info: Loading plugin "system"... Jan 11 00:32:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 107. Jan 11 00:32:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:47 volumio volumio[25610]: info: Loading plugin "appearance"... Jan 11 00:32:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:47 volumio go-librespot[25650]: go-librespot daemon starting... Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=debug msg="app state loaded" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:47 volumio ntpd[872]: IO: Deleting interface #12097 eth0, 169.254.20.131#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=info msg="zeroconf server listening on port 46743" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=debug msg="obtained new client token: AAACwx7XjhxSvcXgr53hcy/T5fr685Cd3yQuwe8tul4Dod1j240bSSHbZhtcseEuf+BORWTg+d2YJV6dWlSR+STrEjNCtZCuXyhaCD2y7+pnmWC7J3t+32olJ/cH98+P8MCaha184sAZevmEkptiFyi0WBqM0Lw9QzNT1mv8//DJG5LJaJqIZnhIz4ovXCguePyBitAE1xHFxhCcsGliXaWf3XrAKQxnqMAzylp0Lv3ytItSwhL9rcVFVg==" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32:47-06:00" level=debug msg="completed challenge" Jan 11 00:32:47 volumio go-librespot[25654]: time="2026-01-11T00:32: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 " Jan 11 00:32:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:48 volumio volumio[25610]: info: Loading plugin "network"... Jan 11 00:32:48 volumio volumio[25610]: info: Refreshing Cached IP Addresses Jan 11 00:32:48 volumio sudo[25662]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 00:32:48 volumio sudo[25662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:48 volumio sudo[25664]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 00:32:48 volumio sudo[25664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:48 volumio sudo[25664]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:48 volumio volumio[25610]: info: Loading plugin "services"... Jan 11 00:32:48 volumio sudo[25662]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:48 volumio volumio[25610]: info: Loading plugin "alsa_controller"... Jan 11 00:32:48 volumio sudo[25671]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 00:32:48 volumio sudo[25671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:48 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 00:32:48 volumio volumio[25610]: info: Loading plugin "wizard"... Jan 11 00:32:48 volumio volumio[25610]: info: Loading plugin "networkfs"... Jan 11 00:32:48 volumio volumio[25610]: info: Starting Udev Watcher for removable devices Jan 11 00:32:48 volumio volumio[25610]: info: Ignoring mount for partition: boot Jan 11 00:32:48 volumio volumio[25610]: info: Ignoring mount for partition: volumio Jan 11 00:32:48 volumio volumio[25610]: info: Ignoring mount for partition: volumio_data Jan 11 00:32:48 volumio volumio[25610]: info: Mounting Device Wikipedia Jan 11 00:32:48 volumio sudo[25701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 11 00:32:48 volumio sudo[25701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:32:48 volumio sudo[25701]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:48 volumio volumio[25610]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 11 00:32:48 volumio volumio[25610]: dmesg(1) may have more information after failed mount system call. Jan 11 00:32:48 volumio volumio[25610]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 11 00:32:48 volumio volumio[25610]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 11 00:32:48 volumio volumio[25610]: dmesg(1) may have more information after failed mount system call. Jan 11 00:32:48 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 00:32:48 volumio volumio[25610]: info: Loading plugin "volumio_command_line_client"... Jan 11 00:32:48 volumio volumio[25610]: info: Loading plugin "upnp"... Jan 11 00:32:48 volumio volumio[25610]: info: [1768113168814] Starting Upmpd Daemon Jan 11 00:32:48 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 00:32:48 volumio volumio[25610]: info: Loading plugin "my_music"... Jan 11 00:32:48 volumio volumio[25610]: info: Loading plugin "mpd"... Jan 11 00:32:49 volumio sudo[25671]: pam_unix(sudo:session): session closed for user root Jan 11 00:32:49 volumio volumio-remote-updater[14193]: [2026-01-11 00:32:49] [connect] Successful connection Jan 11 00:32:49 volumio volumio[25610]: info: Loading plugin "upnp_browser"... Jan 11 00:32:49 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 00:32:50 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.154.124 Jan 11 00:32:50 volumio avahi-daemon[664]: Registering new address record for 169.254.154.124 on eth0.IPv4. Jan 11 00:32:50 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:32:50 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:50 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:50 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 108. Jan 11 00:32:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:50 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.154.124 Jan 11 00:32:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:51 volumio go-librespot[25721]: go-librespot daemon starting... Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=debug msg="app state loaded" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:51 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.154.124 Jan 11 00:32:51 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.154.124 Jan 11 00:32:51 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:32:51 volumio avahi-daemon[664]: Withdrawing address record for 169.254.154.124 on eth0. Jan 11 00:32:51 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:32:51 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:51 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:51 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=info msg="zeroconf server listening on port 43621" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=debug msg="obtained new client token: AABEhuFij4rTtEKEVbYTvifWheZ5XBQsYg8OmLn8sgXl/bNKM9iGgpEoi5hV+G5a8y/ZcyPvXD8GyZG3hYi7hO6PIaKbdrUr6SctkvVFAscV07XfMzGVxLaL0xD17YIokTVcGstDCZOr/gG6BjHDI6/RP0FN8I1/bfVP29D9WKUJJykholNNwO2emWn2oDRWIfDZD0Dmb5c408u3wqddLhcYSdLuqMvfU5AHeSQ5M7yvvcpsqgRg1lACIg==" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32:51-06:00" level=debug msg="completed challenge" Jan 11 00:32:51 volumio go-librespot[25722]: time="2026-01-11T00:32: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 " Jan 11 00:32:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:52 volumio volumio[25610]: info: Loading plugin "alarm-clock"... Jan 11 00:32:52 volumio volumio[25610]: info: Loading plugin "airplay_emulation"... Jan 11 00:32:52 volumio volumio[25610]: info: Starting Shairport Sync Jan 11 00:32:52 volumio volumio[25610]: info: Loading plugin "last_100"... Jan 11 00:32:52 volumio volumio[25610]: info: Loading plugin "webradio"... Jan 11 00:32:52 volumio volumio[25610]: info: Loading plugin "i2s_dacs"... Jan 11 00:32:52 volumio volumio[25610]: info: I2S DAC not set, start Auto-detection Jan 11 00:32:52 volumio volumio[25610]: info: Loading plugin "volumiodiscovery"... Jan 11 00:32:52 volumio volumio[25610]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 00:32:52 volumio volumio[25610]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 00:32:52 volumio volumio[25610]: *** WARNING *** For more information see Jan 11 00:32:52 volumio volumio[25610]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 00:32:52 volumio volumio[25610]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 00:32:52 volumio volumio[25610]: *** WARNING *** For more information see Jan 11 00:32:52 volumio node[25610]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 00:32:52 volumio node[25610]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 00:32:52 volumio node[25610]: *** WARNING *** For more information see Jan 11 00:32:52 volumio node[25610]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 00:32:52 volumio node[25610]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 00:32:52 volumio node[25610]: *** WARNING *** For more information see Jan 11 00:32:52 volumio volumio[25610]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 00:32:52 volumio volumio[25610]: info: Discovery: Started advertising with name: Volumio Jan 11 00:32:52 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 00:32:52 volumio volumio[25610]: info: Loading plugin "bandcamp"... Jan 11 00:32:53 volumio volumio[25610]: info: Plugin calmradio is not enabled Jan 11 00:32:53 volumio volumio[25610]: info: Loading plugin "soundcloud"... Jan 11 00:32:53 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 00:32:54 volumio volumio[25610]: info: Loading plugin "spop"... Jan 11 00:32:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 109. Jan 11 00:32:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:54 volumio go-librespot[25748]: go-librespot daemon starting... Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=debug msg="app state loaded" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:55 volumio volumio[25610]: info: Loading plugin "squeezelite_mc"... Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=info msg="zeroconf server listening on port 44961" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=debug msg="obtained new client token: AABJuaGVQ2dzcpWYxo0AHW9Gqy8a5gUd3edoxOaLvmT1wqFpbU16bnr/0JIt/VtefYbRgpkwjkZAk7A0C10/cdh/eVCfPTu3rBv/cZL/WVGEZwjxrP+hkADD5ta9KJKtinKMryg1C3TdwoUH4muQ8oJ7pRXcvQlyTs4bTdAvLK0qYUfCuFSkwAqCvmCTqLmYTKxgRH8s95ssJZklw88GeOJrCwGoMNrp3AekFpO7+We4MZt1I8Rwgl56AQ==" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32:55-06:00" level=debug msg="completed challenge" Jan 11 00:32:55 volumio go-librespot[25749]: time="2026-01-11T00:32: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 " Jan 11 00:32:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:55 volumio volumio[25610]: info: Loading plugin "youtube2"... Jan 11 00:32:56 volumio volumio[25610]: info: Loading plugin "ytcr"... Jan 11 00:32:56 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.177.71 Jan 11 00:32:56 volumio avahi-daemon[664]: Registering new address record for 169.254.177.71 on eth0.IPv4. Jan 11 00:32:56 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:32:56 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:56 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:56 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:57 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.177.71 Jan 11 00:32:57 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.177.71 Jan 11 00:32:57 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.177.71 Jan 11 00:32:57 volumio avahi-daemon[664]: Withdrawing address record for 169.254.177.71 on eth0. Jan 11 00:32:57 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:32:57 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:32:57 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:57 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:32:57 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:32:58 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 00:32:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 110. Jan 11 00:32:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:32:58 volumio go-librespot[25803]: go-librespot daemon starting... Jan 11 00:32:58 volumio go-librespot[25804]: time="2026-01-11T00:32:58-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:32:58 volumio go-librespot[25804]: time="2026-01-11T00:32:58-06:00" level=debug msg="app state loaded" Jan 11 00:32:58 volumio go-librespot[25804]: time="2026-01-11T00:32:58-06:00" level=debug msg="stored credentials not found" Jan 11 00:32:58 volumio go-librespot[25804]: time="2026-01-11T00:32:58-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:32:59 volumio volumio[25610]: info: Loading plugin "ytmusic"... Jan 11 00:32:59 volumio go-librespot[25804]: time="2026-01-11T00:32: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:32:59 volumio go-librespot[25804]: time="2026-01-11T00:32:59-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:32:59 volumio go-librespot[25804]: time="2026-01-11T00:32:59-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:32:59 volumio go-librespot[25804]: time="2026-01-11T00:32:59-06:00" level=info msg="zeroconf server listening on port 43031" Jan 11 00:32:59 volumio go-librespot[25804]: time="2026-01-11T00:32:59-06:00" level=debug msg="obtained new client token: AADXbQ+DwtjIVjC0vSk8A/hljPdBXD8y+Pu+JgfhqEfQUtLOFlKK0PqmxQjJNcMeWt004F4of/vEaDN6FxYbZfVIo0K4k+Uw6AwudjcQNodxNIWrkrRzGxp3DiV+Rxvryw73SSAO5G5rjXeFwwbmdMNUvwCbE9bpCvsvHR50zhIcafv+W8JvzeWgdhyhAMirEJXSg6BJ+hAR/l8K/rB8h9fZWCYNXtNtwPIZ6vVVbUdoUtWKpMDeIhTs7g==" Jan 11 00:32:59 volumio go-librespot[25804]: time="2026-01-11T00:32:59-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:32:59 volumio go-librespot[25804]: time="2026-01-11T00:32:59-06:00" level=debug msg="completed keyexchange" Jan 11 00:32:59 volumio go-librespot[25804]: time="2026-01-11T00:32:59-06:00" level=debug msg="completed challenge" Jan 11 00:32:59 volumio go-librespot[25804]: time="2026-01-11T00:32:59-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:32:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:32:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:32:59 volumio volumio[25610]: info: Plugin now_playing is not enabled Jan 11 00:32:59 volumio volumio[25610]: info: Loading plugin "outputs"... Jan 11 00:32:59 volumio volumio[25610]: info: Loading plugin "albumart"... Jan 11 00:32:59 volumio volumio[25610]: info: Plugin example_plugin is not enabled Jan 11 00:32:59 volumio volumio[25610]: info: Loading plugin "inputs"... Jan 11 00:32:59 volumio volumio[25610]: info: Loading plugin "updater_comm"... Jan 11 00:33:00 volumio volumio[25610]: info: Plugin mpdemulation is not enabled Jan 11 00:33:00 volumio volumio[25610]: info: Loading plugin "rest_api"... Jan 11 00:33:00 volumio volumio[25610]: info: Loading plugin "websocket"... Jan 11 00:33:00 volumio volumio[25610]: info: Starting Socket.io Server version 1.7.4 Jan 11 00:33:00 volumio volumio[25610]: info: Plugin fusiondsp is not enabled Jan 11 00:33:00 volumio volumio[25610]: info: Plugin mpdoutput is not enabled Jan 11 00:33:00 volumio volumio[25610]: info: Plugin RoonBridge is not enabled Jan 11 00:33:00 volumio volumio[25610]: info: Loading plugin "podcast"... Jan 11 00:33:00 volumio volumio[25610]: info: ControllerPodcast::constructor Jan 11 00:33:00 volumio volumio[25610]: info: Loading plugin "volusonic"... Jan 11 00:33:00 volumio volumio[25812]: Forking 3 albumart workers Jan 11 00:33:01 volumio volumio-remote-updater[14193]: [2026-01-11 00:33:01] [connect] Successful connection Jan 11 00:33:02 volumio volumio[25824]: Starting albumart workers Jan 11 00:33:02 volumio volumio[25823]: Starting albumart workers Jan 11 00:33:02 volumio volumio[25610]: info: Applying required configuration parameters for plugin volusonic Jan 11 00:33:02 volumio volumio[25822]: Starting albumart workers Jan 11 00:33:02 volumio volumio[25610]: info: Loading plugin "backup_restore"... Jan 11 00:33:02 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.59.119 Jan 11 00:33:02 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:33:02 volumio avahi-daemon[664]: Registering new address record for 169.254.59.119 on eth0.IPv4. Jan 11 00:33:02 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:02 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:33:02 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:02 volumio volumio[25610]: info: Applying required configuration parameters for plugin backup_restore Jan 11 00:33:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 111. Jan 11 00:33:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:02 volumio volumio[25610]: info: Plugin rpi_eeprom_config is not enabled Jan 11 00:33:02 volumio volumio[25610]: info: Plugin rpi_eeprom_updater is not enabled Jan 11 00:33:02 volumio volumio[25610]: info: Loading plugin "scheduledrestart"... Jan 11 00:33:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:02 volumio go-librespot[25871]: go-librespot daemon starting... Jan 11 00:33:02 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.59.119 Jan 11 00:33:02 volumio go-librespot[25872]: time="2026-01-11T00:33:02-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:33:02 volumio go-librespot[25872]: time="2026-01-11T00:33:02-06:00" level=debug msg="app state loaded" Jan 11 00:33:02 volumio go-librespot[25872]: time="2026-01-11T00:33:02-06:00" level=debug msg="stored credentials not found" Jan 11 00:33:02 volumio go-librespot[25872]: time="2026-01-11T00:33:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:33:03 volumio volumio[25610]: info: Applying required configuration parameters for plugin scheduledrestart Jan 11 00:33:03 volumio volumio[25610]: info: Plugin Bluetoothremote is not enabled Jan 11 00:33:03 volumio volumio[25610]: info: Plugin music_services_shield is not enabled Jan 11 00:33:03 volumio volumio[25610]: info: Loading plugin "Systeminfo"... Jan 11 00:33:03 volumio go-librespot[25872]: time="2026-01-11T00:33:03-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 00:33:03 volumio go-librespot[25872]: time="2026-01-11T00:33:03-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 00:33:03 volumio go-librespot[25872]: time="2026-01-11T00:33:03-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 00:33:03 volumio ntpd[872]: IO: Listen normally on 12098 eth0 169.254.59.119:123 Jan 11 00:33:03 volumio ntpd[872]: IO: new interface(s) found: waking up resolver Jan 11 00:33:03 volumio go-librespot[25872]: time="2026-01-11T00:33:03-06:00" level=info msg="zeroconf server listening on port 35369" Jan 11 00:33:03 volumio go-librespot[25872]: time="2026-01-11T00:33:03-06:00" level=debug msg="obtained new client token: AAAjB1GPibatYFqd6O8e9IPZFq9dExxGapie3By3vepzDyhsk7O0Sx17yVWFegnobHYrMhUamnd/zi0tOgPhLCZQb2gojH8Kk3SdI1dLFw6nrf/wARITsL5Et620uMkm0ViY78RUPTM2z2vMtaArmZSrlkg5+BUjYMIBv9hC50Cs2yZXzPkwqD0diMTepzwieq0yUyR07T7kWRcghWZU9KGbx/ruy/q4mTmUfDMXld0XQYPEzWBm1D8dfw==" Jan 11 00:33:03 volumio go-librespot[25872]: time="2026-01-11T00:33:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:33:03 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.59.119 Jan 11 00:33:03 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.59.119 Jan 11 00:33:03 volumio avahi-daemon[664]: Withdrawing address record for 169.254.59.119 on eth0. Jan 11 00:33:03 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:33:03 volumio go-librespot[25872]: time="2026-01-11T00:33:03-06:00" level=debug msg="completed keyexchange" Jan 11 00:33:03 volumio go-librespot[25872]: time="2026-01-11T00:33:03-06:00" level=debug msg="completed challenge" Jan 11 00:33:03 volumio go-librespot[25872]: time="2026-01-11T00:33:03-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:33:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:33:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:33:03 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:33:03 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:03 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:33:03 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:04 volumio volumio[25610]: info: Plugin peppymeterbasic is not enabled Jan 11 00:33:04 volumio volumio[25610]: info: Loading plugin "peppyspectrum"... Jan 11 00:33:04 volumio volumio[25610]: info: Loading i18n strings for locale en Jan 11 00:33:04 volumio volumio[25610]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 00:33:04 volumio volumio[25610]: Updating browse sources language Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::initPlayerControls Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 00:33:04 volumio volumio[25610]: Express server listening on port 3000 Jan 11 00:33:04 volumio volumio[25610]: [Metrics] WebUI: 19s 98.52ms Jan 11 00:33:04 volumio volumio[25610]: info: CoreStateMachine::resetVolumioState Jan 11 00:33:04 volumio volumio[25610]: info: CoreStateMachine::getcurrentVolume Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 00:33:04 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:33:05 volumio sudo[25919]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 00:33:05 volumio sudo[25919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:05 volumio sudo[25919]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:05 volumio sudo[25921]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 00:33:05 volumio sudo[25921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:05 volumio sudo[25921]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:05 volumio volumio[25610]: info: Volumio Network Manager: Network status updated: 1 Jan 11 00:33:05 volumio volumio[25610]: info: VolumeController:: Volume=100 Mute =false Jan 11 00:33:05 volumio volumio[25610]: info: CoreStateMachine::pushState Jan 11 00:33:05 volumio volumio[25610]: info: CorePlayQueue::getTrack 0 Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioPushState Jan 11 00:33:05 volumio volumio[25610]: info: CoreStateMachine::updateTrackBlock Jan 11 00:33:05 volumio volumio[25610]: info: CorePlayQueue::getTrackBlock Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 00:33:05 volumio volumio-remote-updater[14193]: [2026-01-11 00:33:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768113181 101 Jan 11 00:33:05 volumio ntpd[872]: IO: Deleting interface #12098 eth0, 169.254.59.119#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Jan 11 00:33:05 volumio volumio[25610]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 11 00:33:05 volumio volumio[25610]: info: Reloading queue from file Jan 11 00:33:05 volumio volumio[25610]: info: CoreStateMachine::setRepeat null single undefined Jan 11 00:33:05 volumio volumio[25610]: info: CoreStateMachine::pushState Jan 11 00:33:05 volumio volumio[25610]: info: CorePlayQueue::getTrack 0 Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioPushState Jan 11 00:33:05 volumio volumio[25610]: info: CoreStateMachine::setRandom null Jan 11 00:33:05 volumio volumio[25610]: info: CoreStateMachine::pushState Jan 11 00:33:05 volumio volumio[25610]: info: CorePlayQueue::getTrack 0 Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioPushState Jan 11 00:33:05 volumio volumio[25610]: info: Setting Device type: Raspberry PI Jan 11 00:33:05 volumio volumio[25610]: info: VolumeController:: Volume=100 Mute =false Jan 11 00:33:05 volumio volumio[25610]: info: CoreStateMachine::pushState Jan 11 00:33:05 volumio volumio[25610]: info: CorePlayQueue::getTrack 0 Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioPushState Jan 11 00:33:05 volumio volumio[25610]: info: Completed loading Core Plugins Jan 11 00:33:05 volumio volumio[25610]: info: Preparing to generate the ALSA configuration file Jan 11 00:33:05 volumio sudo[25935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 11 00:33:05 volumio sudo[25935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:05 volumio volumio[25610]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 11 00:33:05 volumio volumio[25610]: info: Discovery: Found device Volumio Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioGetState Jan 11 00:33:05 volumio volumio[25610]: info: CorePlayQueue::getTrack 0 Jan 11 00:33:05 volumio volumio[25610]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 11 00:33:05 volumio volumio[25610]: info: Discovery: Found device Volumio Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioGetState Jan 11 00:33:05 volumio volumio[25610]: info: CorePlayQueue::getTrack 0 Jan 11 00:33:05 volumio volumio[25610]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 00:33:05 volumio volumio[25610]: info: Reading ALSA contributions from plugins. Jan 11 00:33:05 volumio sudo[25935]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:05 volumio volumio[25610]: info: Upmpdcli Daemon Started Jan 11 00:33:05 volumio volumio[25610]: info: Asound.conf file unchanged, so no further update is needed Jan 11 00:33:05 volumio volumio[25610]: info: Output device has changed, restarting MPD Jan 11 00:33:05 volumio volumio[25610]: info: Output device has changed, restarting Shairport Sync Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:33:05 volumio sudo[25938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 00:33:05 volumio sudo[25938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:05 volumio sudo[25938]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:05 volumio sudo[25940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 00:33:05 volumio sudo[25940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:05 volumio volumio[25610]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 00:33:05 volumio volumio[25610]: info: ___________ START PLUGINS ___________ Jan 11 00:33:05 volumio volumio[25610]: info: ControllerMpd::onStart: Initializing MPD Jan 11 00:33:05 volumio volumio[25610]: info: Creating MPD Configuration file Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:33:05 volumio volumio[25610]: info: [1768113185754] CoreMusicLibrary::Adding element Media Servers Jan 11 00:33:05 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:05 volumio sudo[25948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 00:33:05 volumio sudo[25950]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 00:33:05 volumio sudo[25948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:05 volumio sudo[25950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:05 volumio sudo[25948]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:33:05 volumio volumio[25610]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:33:05 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 11 00:33:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 11 00:33:05 volumio systemd[1]: mpd.service: Consumed 5.568s CPU time. Jan 11 00:33:05 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 11 00:33:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 11 00:33:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 11 00:33:05 volumio volumio[25610]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:33:05 volumio volumio[25610]: info: [1768113185884] CoreMusicLibrary::Adding element Last_100 Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:33:05 volumio volumio[25610]: info: [1768113185889] CoreMusicLibrary::Adding element Webradio Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 00:33:05 volumio volumio[25610]: info: Initializing BBC Radios Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:33:05 volumio volumio[25610]: info: [1768113185957] CoreMusicLibrary::Adding element Bandcamp Discover Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:05 volumio volumio[25610]: Cannot find translation for source Bandcamp Discover Jan 11 00:33:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:33:05 volumio volumio[25610]: info: [1768113185971] CoreMusicLibrary::Adding element SoundCloud Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:05 volumio volumio[25610]: Cannot find translation for source Bandcamp Discover Jan 11 00:33:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 11 00:33:05 volumio volumio[25610]: Cannot find translation for source SoundCloud Jan 11 00:33:05 volumio volumio[25610]: info: Creating Spotify config file Jan 11 00:33:05 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio sudo[25975]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 00:33:06 volumio sudo[25975]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 11 00:33:06 volumio sudo[25975]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:06 volumio volumio[25610]: info: [squeezelite_mc] Starting proxy server... Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:33:06 volumio volumio[25610]: info: [1768113186330] CoreMusicLibrary::Adding element YouTube2 Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Bandcamp Discover Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source SoundCloud Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube2 Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:33:06 volumio volumio[25610]: info: [1768113186348] CoreMusicLibrary::Adding element YouTube Music Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Bandcamp Discover Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source SoundCloud Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube2 Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube Music Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:33:06 volumio volumio[25610]: info: [1768113186360] CoreMusicLibrary::Adding element Podcast Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Bandcamp Discover Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source SoundCloud Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube2 Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube Music Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Podcast Jan 11 00:33:06 volumio volumio[25610]: info: Loading i18n strings for locale en Jan 11 00:33:06 volumio volumio[25610]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 11 00:33:06 volumio volumio[25610]: Updating browse sources language Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Bandcamp Discover Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source SoundCloud Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube2 Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube Music Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Podcast Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Bandcamp Discover Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source SoundCloud Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube2 Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube Music Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Podcast Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:33:06 volumio volumio[25610]: info: [1768113186407] CoreMusicLibrary::Adding element Volusonic Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Bandcamp Discover Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source SoundCloud Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube2 Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source YouTube Music Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Podcast Jan 11 00:33:06 volumio volumio[25610]: Cannot find translation for source Volusonic Jan 11 00:33:06 volumio volumio[25610]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 00:33:06 volumio volumio[25610]: info: Volumio Calling Home Jan 11 00:33:06 volumio volumio[25610]: info: [squeezelite_mc] Proxy server started on port 34839 Jan 11 00:33:06 volumio volumio[25610]: info: Preparing to generate the ALSA configuration file Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 00:33:06 volumio volumio[25610]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 11 00:33:06 volumio volumio[25610]: info: Reading ALSA contributions from plugins. Jan 11 00:33:06 volumio volumio[25610]: info: MPD Permissions set Jan 11 00:33:06 volumio volumio[25610]: info: MPD Permissions set Jan 11 00:33:06 volumio volumio[25610]: info: Spotify config file written Jan 11 00:33:06 volumio sudo[25984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 11 00:33:06 volumio sudo[25984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:06 volumio volumio[25610]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 00:33:06 volumio volumio[25610]: info: VolumeController:: Volume=100 Mute =false Jan 11 00:33:06 volumio volumio[25610]: info: CoreStateMachine::pushState Jan 11 00:33:06 volumio volumio[25610]: info: CorePlayQueue::getTrack 0 Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::volumioPushState Jan 11 00:33:06 volumio volumio[25610]: info: [squeezelite_mc] Server discovery started Jan 11 00:33:06 volumio volumio[25610]: info: [squeezelite_mc] Player finder started Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 11 00:33:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 112. Jan 11 00:33:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:06 volumio volumio[25610]: info: No need to fix Spotify hosts Jan 11 00:33:06 volumio go-librespot[25988]: go-librespot daemon starting... Jan 11 00:33:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:06 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 11 00:33:06 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 11 00:33:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:06 volumio go-librespot[26000]: go-librespot daemon starting... Jan 11 00:33:06 volumio sudo[25984]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=debug msg="app state loaded" Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=debug msg="stored credentials not found" Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:33:07 volumio volumio[25610]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 11 00:33:07 volumio volumio[25610]: info: Volumio called home Jan 11 00:33:07 volumio volumio[25610]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 11 00:33:07 volumio volumio[25610]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 11 00:33:07 volumio volumio[25610]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Jan 11 00:33:07 volumio volumio[25610]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 00:33:07 volumio volumio[25610]: SPOTIFY: BQCyM9cX9JJvHzHLbArp1GtlJN5eph8xqFK4ujeR8z-zJoOdiUypbJ4PZF7qzJ5ec1t-MkIbC9iwmbuJyF-JeYiLnZ3I_AElHTXzpSaEYgQmEHNcGhpeVNw0mrcdU-9IBiz3EJ1yq_TdGBMDPJODHqupc4p-PS4lw8MLS-6ZgLRnrY64Fezcmk2bvvvNCvjlS34u9n-zDMVcNnjXAw_kZ0wgZvHqb4MuuGfARYY Jan 11 00:33:07 volumio volumio[25610]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:33:07 volumio volumio[25610]: info: New Spotify access token = BQCyM9cX9JJvHzHLbArp1GtlJN5eph8xqFK4ujeR8z-zJoOdiUypbJ4PZF7qzJ5ec1t-MkIbC9iwmbuJyF-JeYiLnZ3I_AElHTXzpSaEYgQmEHNcGhpeVNw0mrcdU-9IBiz3EJ1yq_TdGBMDPJODHqupc4p-PS4lw8MLS-6ZgLRnrY64Fezcmk2bvvvNCvjlS34u9n-zDMVcNnjXAw_kZ0wgZvHqb4MuuGfARYY Jan 11 00:33:07 volumio volumio[25610]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=info msg="zeroconf server listening on port 44295" Jan 11 00:33:07 volumio volumio[25610]: info: Starting Shairport Sync Jan 11 00:33:07 volumio volumio[25610]: info: Starting Shairport Sync Jan 11 00:33:07 volumio volumio[25610]: info: Starting Shairport Sync Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=debug msg="obtained new client token: AAD6LXBQmPsaeNJ4wp6SUOOlLn3hNhnDqyhP8TnQ+E6490YsDrL/aS7TV2LCB6KdMqc2VI8lZEQRRerDpl7JwBSlkbnWazubZGtbNxS6Xfj3UlvZ8PtEY7lOetM41Lw7/zURkzr8H4P3fGLWNMzK32Lwd8L/XYcevaVz7TLo6x0FZFBnGgF2L0L9LwJ4mopKWiULWT7jyeer+FMU1ektCpyALiYs13fJaODaTnBrh5+cLr1yvm/qNf/Log==" Jan 11 00:33:07 volumio sudo[26012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 00:33:07 volumio sudo[26012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:07 volumio sudo[26014]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 00:33:07 volumio sudo[26014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:33:07 volumio sudo[26016]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 00:33:07 volumio sudo[26016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:07 volumio sudo[26010]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Jan 11 00:33:07 volumio sudo[26010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:07 volumio sudo[26010]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=debug msg="completed keyexchange" Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=debug msg="completed challenge" Jan 11 00:33:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 00:33:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 00:33:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 00:33:07 volumio systemd[1]: shairport-sync.service: Consumed 1.995s CPU time. Jan 11 00:33:07 volumio go-librespot[26001]: time="2026-01-11T00:33:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:33:07 volumio volumio[25610]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 11 00:33:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 00:33:07 volumio volumio[25610]: info: Asound.conf file unchanged, so no further update is needed Jan 11 00:33:07 volumio volumio[25610]: info: Output device has changed, restarting MPD Jan 11 00:33:07 volumio sudo[26012]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:33:07 volumio sudo[26014]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:33:08 volumio volumio[25610]: info: Output device has changed, restarting Shairport Sync Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:33:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 00:33:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 00:33:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 00:33:08 volumio sudo[26026]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 11 00:33:08 volumio sudo[26026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:08 volumio sudo[26028]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 00:33:08 volumio sudo[26028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:08 volumio sudo[26030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 00:33:08 volumio sudo[26030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:08 volumio sudo[26028]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:08 volumio sudo[26026]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:08 volumio volumio[25610]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 00:33:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 00:33:08 volumio sudo[26016]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:08 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 11 00:33:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 11 00:33:08 volumio systemd[1]: mpd.service: Consumed 2.095s CPU time. Jan 11 00:33:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 11 00:33:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 11 00:33:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 11 00:33:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 11 00:33:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 11 00:33:08 volumio volumio[25610]: info: MPD Permissions set Jan 11 00:33:08 volumio volumio[25610]: info: Shairport-Sync Started Jan 11 00:33:08 volumio volumio[25610]: Error adding Membership: Error: addMembership EINVAL Jan 11 00:33:08 volumio volumio[25610]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 11 00:33:08 volumio volumio[25610]: info: Shairport-Sync Started Jan 11 00:33:08 volumio volumio[25610]: info: Shairport-Sync Started Jan 11 00:33:08 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.211.132 Jan 11 00:33:08 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:33:08 volumio avahi-daemon[664]: Registering new address record for 169.254.211.132 on eth0.IPv4. Jan 11 00:33:08 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:08 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:33:08 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:08 volumio sudo[26061]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 00:33:08 volumio sudo[26061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:08 volumio sudo[26061]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:08 volumio volumio[25610]: info: CoreCommandRouter::volumioGetState Jan 11 00:33:08 volumio volumio[25610]: info: CorePlayQueue::getTrack 0 Jan 11 00:33:08 volumio volumio[25610]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 11 00:33:08 volumio sudo[26058]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 00:33:08 volumio sudo[26058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 11 00:33:08 volumio volumio[25610]: info: Starting Shairport Sync Jan 11 00:33:08 volumio sudo[26058]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:09 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.211.132 Jan 11 00:33:09 volumio sudo[26099]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 11 00:33:09 volumio sudo[26099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:09 volumio sudo[26102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 00:33:09 volumio sudo[26102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:09 volumio volumio[25610]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Jan 11 00:33:09 volumio volumio[25610]: info: Spotify Successfully logged in Jan 11 00:33:09 volumio volumio[25610]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 00:33:09 volumio volumio[25610]: info: [1768113189177] CoreMusicLibrary::Adding element Spotify Jan 11 00:33:09 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 00:33:09 volumio volumio[25610]: Cannot find translation for source Bandcamp Discover Jan 11 00:33:09 volumio volumio[25610]: Cannot find translation for source SoundCloud Jan 11 00:33:09 volumio volumio[25610]: Cannot find translation for source YouTube2 Jan 11 00:33:09 volumio volumio[25610]: Cannot find translation for source YouTube Music Jan 11 00:33:09 volumio volumio[25610]: Cannot find translation for source Podcast Jan 11 00:33:09 volumio volumio[25610]: Cannot find translation for source Volusonic Jan 11 00:33:09 volumio volumio[25610]: Cannot find translation for source Spotify Jan 11 00:33:09 volumio systemd[1]: Reloading. Jan 11 00:33:09 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:09 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:09 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 00:33:09 volumio volumio[25610]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 00:33:09 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.211.132 Jan 11 00:33:09 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.211.132 Jan 11 00:33:09 volumio avahi-daemon[664]: Withdrawing address record for 169.254.211.132 on eth0. Jan 11 00:33:09 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:33:09 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:33:10 volumio volumio[25610]: info: go-librespot daemon successfully initialized Jan 11 00:33:11 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 11 00:33:11 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 11 00:33:11 volumio sudo[26099]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:11 volumio volumio[25610]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:33:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 11 00:33:11 volumio sudo[26141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:33:11 volumio sudo[26141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:11 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:11 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:33:11 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:11 volumio go-librespot[26143]: go-librespot daemon starting... Jan 11 00:33:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 11 00:33:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 11 00:33:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 00:33:11 volumio systemd[1]: shairport-sync.service: Consumed 1.494s CPU time. Jan 11 00:33:11 volumio go-librespot[26144]: time="2026-01-11T00:33:11-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:33:11 volumio go-librespot[26144]: time="2026-01-11T00:33:11-06:00" level=debug msg="app state loaded" Jan 11 00:33:11 volumio go-librespot[26144]: time="2026-01-11T00:33:11-06:00" level=debug msg="stored credentials not found" Jan 11 00:33:11 volumio go-librespot[26144]: time="2026-01-11T00:33:11-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:33:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 11 00:33:11 volumio sudo[26102]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:11 volumio volumio[25610]: info: Shairport-Sync Started Jan 11 00:33:11 volumio sudo[26141]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:11 volumio volumio[25610]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 11 00:33:11 volumio sudo[26165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 11 00:33:11 volumio sudo[26165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:11 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 11 00:33:12 volumio go-librespot[26144]: time="2026-01-11T00:33: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:33:12 volumio go-librespot[26144]: time="2026-01-11T00:33:12-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:33:12 volumio go-librespot[26144]: time="2026-01-11T00:33:12-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:33:12 volumio go-librespot[26144]: time="2026-01-11T00:33:12-06:00" level=info msg="zeroconf server listening on port 34257" Jan 11 00:33:12 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 11 00:33:12 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 11 00:33:12 volumio sudo[26165]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:12 volumio go-librespot[26144]: time="2026-01-11T00:33:12-06:00" level=debug msg="obtained new client token: AABTa+EqDJx0K2F2yLCByd6hnI4P8W8xYzzD7pbb/Yy7ZHD6BUmSCegxxwD3LJzGcM3yW9RRk0LABf2RjnC16+ZFAgaXhlCGpIdiYE585PBCqHq67mpNK3eC0/vJTRIIS7nXbLa2nnZ4wBEouVpiWJ4Ad3E0tVr6aCRBog47mVV+Mdnsup3HsrH+nnWbnooeyHsoDh5eFhwg3VWRoP8MUmQauCypLmBujxHDBj5Xib50YjGmh0fgyYM=" Jan 11 00:33:12 volumio go-librespot[26144]: time="2026-01-11T00:33:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:33:12 volumio go-librespot[26144]: time="2026-01-11T00:33:12-06:00" level=debug msg="completed keyexchange" Jan 11 00:33:12 volumio go-librespot[26144]: time="2026-01-11T00:33:12-06:00" level=debug msg="completed challenge" Jan 11 00:33:12 volumio go-librespot[26144]: time="2026-01-11T00:33: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 " Jan 11 00:33:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:33:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:33:12 volumio volumio[25610]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:33:12 volumio kernel: hwmon hwmon1: Voltage normalised Jan 11 00:33:12 volumio sudo[26170]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:33:12 volumio sudo[26170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:12 volumio sudo[26170]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:12 volumio volumio[25610]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 11 00:33:12 volumio sudo[26175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 11 00:33:12 volumio sudo[26175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:12 volumio sudo[26175]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:12 volumio volumio[25610]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 11 00:33:12 volumio sudo[26178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 11 00:33:12 volumio sudo[26178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:12 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 11 00:33:12 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 11 00:33:12 volumio sudo[26178]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:13 volumio mpd[26103]: 2026-01-11T00:33:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 00:33:13 volumio volumio[25610]: info: Initializing connection to go-librespot Websocket Jan 11 00:33:13 volumio volumio[25610]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 00:33:13 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 11 00:33:13 volumio sudo[25950]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:13 volumio sudo[25940]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:13 volumio sudo[26030]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:13 volumio volumio[25610]: error: MPD error: The expression evaluated to a falsy value: Jan 11 00:33:13 volumio volumio[25610]: assert.ok(self.idling) Jan 11 00:33:13 volumio volumio[25610]: error: The expression evaluated to a falsy value: Jan 11 00:33:13 volumio volumio[25610]: assert.ok(self.idling) Jan 11 00:33:13 volumio volumio[25610]: error: MPD error: The expression evaluated to a falsy value: Jan 11 00:33:13 volumio volumio[25610]: assert.ok(self.idling) Jan 11 00:33:13 volumio volumio[25610]: error: The expression evaluated to a falsy value: Jan 11 00:33:13 volumio volumio[25610]: assert.ok(self.idling) Jan 11 00:33:13 volumio volumio[25610]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:33:13 volumio volumio[25610]: error: updateQueue error: null Jan 11 00:33:13 volumio volumio[25610]: info: MPD running with PID26103 Jan 11 00:33:13 volumio volumio[25610]: ,establishing connection Jan 11 00:33:13 volumio volumio[25610]: error: updateQueue error: null Jan 11 00:33:13 volumio sudo[26189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:33:13 volumio sudo[26189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:13 volumio sudo[26189]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:14 volumio volumio[25610]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:33:14 volumio sudo[26192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:33:14 volumio sudo[26192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:14 volumio sudo[26192]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:14 volumio volumio[25610]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:33:14 volumio sudo[26195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:33:14 volumio sudo[26195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:14 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.97.195 Jan 11 00:33:14 volumio avahi-daemon[664]: Registering new address record for 169.254.97.195 on eth0.IPv4. Jan 11 00:33:14 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:33:14 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:14 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:33:14 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:14 volumio sudo[26195]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:14 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.97.195 Jan 11 00:33:14 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.97.195 Jan 11 00:33:14 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.97.195 Jan 11 00:33:14 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:33:14 volumio avahi-daemon[664]: Withdrawing address record for 169.254.97.195 on eth0. Jan 11 00:33:15 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:33:15 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:15 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:33:15 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:15 volumio volumio[25610]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:33:15 volumio sudo[26230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:33:15 volumio sudo[26230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 11 00:33:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:15 volumio go-librespot[26232]: go-librespot daemon starting... Jan 11 00:33:15 volumio sudo[26230]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=debug msg="app state loaded" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=debug msg="stored credentials not found" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=info msg="zeroconf server listening on port 41005" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=debug msg="obtained new client token: AABy0yHd+UOFlrmcHxsN7KovPe0jeMNvREiKOh80p0eLCMsydjx3TyVWBJ9gAOPu4yiYrW8ml7G5YNr2A6P0LvFnGdzW+X3P0UF5UlmU+JxTmhUlcQTHcn8fMniOq8tqn4LZ298imiPIOyN/B8ItdEnPyrIVPxW1sYYE3W9A+XsSbRu1Jg1wQdfE5Oijilv8vx6RwFQw+5zYp1G3bxc6+t5hI23go6NdZJYgeNg3vuqWIZGiLNM+jyCMkA==" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=debug msg="completed keyexchange" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=debug msg="completed challenge" Jan 11 00:33:15 volumio go-librespot[26233]: time="2026-01-11T00:33:15-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:33:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:33:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:33:16 volumio volumio[25610]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 11 00:33:16 volumio sudo[26241]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 11 00:33:16 volumio sudo[26241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:16 volumio sudo[26241]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:16 volumio volumio[25610]: info: Completed starting Core Plugins Jan 11 00:33:16 volumio volumio[25610]: info: ------------------------------------------- Jan 11 00:33:16 volumio volumio[25610]: info: ----- MyVolumio plugins startup ---- Jan 11 00:33:16 volumio volumio[25610]: info: ------------------------------------------- Jan 11 00:33:16 volumio volumio[25610]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 11 00:33:16 volumio volumio[25610]: info: Initializing connection to go-librespot Websocket Jan 11 00:33:16 volumio volumio[25610]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 11 00:33:16 volumio sudo[26244]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 00:33:16 volumio sudo[26244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:16 volumio sudo[26246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 00:33:16 volumio sudo[26246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:16 volumio sudo[26248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 11 00:33:16 volumio sudo[26248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 00:33:16 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 11 00:33:16 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 11 00:33:16 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 11 00:33:16 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 11 00:33:16 volumio sudo[26246]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:16 volumio sudo[26248]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:16 volumio mpd_monitor.sh[26252]: MPD Monitor Service: Starting MPD Monitor Service Jan 11 00:33:16 volumio sudo[26244]: pam_unix(sudo:session): session closed for user root Jan 11 00:33:16 volumio volumio[25610]: info: Successfully started MPD Monitor Jan 11 00:33:16 volumio volumio[25610]: info: Successfully started MPD Monitor Jan 11 00:33:16 volumio volumio[25610]: info: Successfully started MPD Monitor Jan 11 00:33:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 11 00:33:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:19 volumio go-librespot[26270]: go-librespot daemon starting... Jan 11 00:33:19 volumio go-librespot[26271]: time="2026-01-11T00:33:19-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:33:19 volumio go-librespot[26271]: time="2026-01-11T00:33:19-06:00" level=debug msg="app state loaded" Jan 11 00:33:19 volumio go-librespot[26271]: time="2026-01-11T00:33:19-06:00" level=debug msg="stored credentials not found" Jan 11 00:33:19 volumio go-librespot[26271]: time="2026-01-11T00:33:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:33:19 volumio volumio[25610]: info: Initializing connection to go-librespot Websocket Jan 11 00:33:19 volumio go-librespot[26271]: time="2026-01-11T00:33: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-gew4.spotify.com:80]" Jan 11 00:33:19 volumio go-librespot[26271]: time="2026-01-11T00:33:19-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 11 00:33:19 volumio go-librespot[26271]: time="2026-01-11T00:33:19-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 11 00:33:19 volumio go-librespot[26271]: time="2026-01-11T00:33:19-06:00" level=info msg="zeroconf server listening on port 38907" Jan 11 00:33:19 volumio go-librespot[26271]: time="2026-01-11T00:33:19-06:00" level=debug msg="obtained new client token: AAAMITUdP1ujpzF2qNo3QP0rNKjdCM/NlvPY3EaU2lD8bpNyjYrB/tWhtcnWzfypPdYm78YFt4x0xUpJnq0/4sAPmyV77zL1SJ9gk53P1DI+yd613y11Jz/7/jdzW+EEu4z7t8m/cD3JfXjKeUVX0YKdWOhG+XJ9jf5DuW5RilUUkgnBHfINg3GRZCi6jnQmWRNuciVtB6d91dgBcc4nvUz12jxBokTqHeCFt86kHRYeYYIZU82Sa11goQ==" Jan 11 00:33:20 volumio go-librespot[26271]: time="2026-01-11T00:33:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:33:20 volumio go-librespot[26271]: time="2026-01-11T00:33:20-06:00" level=debug msg="new websocket client" Jan 11 00:33:20 volumio go-librespot[26271]: time="2026-01-11T00:33:20-06:00" level=debug msg="completed keyexchange" Jan 11 00:33:20 volumio go-librespot[26271]: time="2026-01-11T00:33:20-06:00" level=debug msg="completed challenge" Jan 11 00:33:20 volumio go-librespot[26271]: time="2026-01-11T00:33:20-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:33:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:33:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:33:20 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.99.100 Jan 11 00:33:20 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 11 00:33:20 volumio avahi-daemon[664]: Registering new address record for 169.254.99.100 on eth0.IPv4. Jan 11 00:33:20 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:20 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:33:20 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:20 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.99.100 Jan 11 00:33:20 volumio volumio[25610]: info: Connection to go-librespot Websocket established Jan 11 00:33:20 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.99.100 Jan 11 00:33:20 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.99.100 Jan 11 00:33:20 volumio avahi-daemon[664]: Withdrawing address record for 169.254.99.100 on eth0. Jan 11 00:33:20 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 11 00:33:20 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:20 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 11 00:33:20 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 11 00:33:20 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 11 00:33:20 volumio volumio[25610]: info: Connection to go-librespot Websocket closed Jan 11 00:33:20 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 11 00:33:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 11 00:33:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 11 00:33:23 volumio go-librespot[26312]: go-librespot daemon starting... Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=info msg="running go-librespot 0.4.0" Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=debug msg="app state loaded" Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=debug msg="stored credentials not found" Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33: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]" Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33: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]" Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33: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]" Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=info msg="zeroconf server listening on port 46169" Jan 11 00:33:23 volumio volumio[25610]: info: Getting Spotify volume Jan 11 00:33:23 volumio volumio[25610]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=debug msg="obtained new client token: AADgrdWug3Ipq5v2Gr8wHEa5nxQmX8vlq4AswE+GeCE56PmijcN/4mFb9nOm0pnbFCCHUp6kgHoF2dKOqWJm3XwFk8itvkuxQYrBihVB1aUV0m8GujDF/6DBGZ+FtVHpLoAUARvcj7DQgl+15QtlzgRKMMia7j9Zkba5Odo7m3x+CF6CiVDW+ti4cwtBwYjrxnmdhxFR2Tn70Jlg/IToULhVw9OvPOQvlM+KT8gXIGiZah7Hp/kgTQrk8g==" Jan 11 00:33:23 volumio volumio[25610]: info: CoreCommandRouter::volumioGetState Jan 11 00:33:23 volumio volumio[25610]: info: CorePlayQueue::getTrack 0 Jan 11 00:33:23 volumio volumio[25610]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 11 00:33:23 volumio volumio[25610]: SPOTIFY: SPOTIFY VOLUME undefined Jan 11 00:33:23 volumio volumio[25610]: SPOTIFY: VOLUMIO VOLUME 100 Jan 11 00:33:23 volumio volumio[25610]: info: Aligning Spotify Volume to Volumio Volume Jan 11 00:33:23 volumio volumio[25610]: info: CoreCommandRouter::volumioGetState Jan 11 00:33:23 volumio volumio[25610]: info: CorePlayQueue::getTrack 0 Jan 11 00:33:23 volumio volumio[25610]: info: Setting Spotify Volume from Volumio: 100 Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=debug msg="completed keyexchange" Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=debug msg="completed challenge" Jan 11 00:33:23 volumio volumio[25610]: info: Initializing connection to go-librespot Websocket Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=debug msg="new websocket client" Jan 11 00:33:23 volumio volumio[25610]: info: Connection to go-librespot Websocket established Jan 11 00:33:23 volumio go-librespot[26313]: time="2026-01-11T00:33:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 11 00:33:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 00:33:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 00:33:23 volumio volumio[25610]: info: Connection to go-librespot Websocket closed Jan 11 00:33:23 volumio volumio[25610]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 00:33:23 volumio volumio[25610]: Error: socket hang up Jan 11 00:33:23 volumio volumio[25610]: at connResetException (node:internal/errors:720:14) Jan 11 00:33:23 volumio volumio[25610]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 11 00:33:23 volumio volumio[25610]: at Socket.emit (node:events:526:35) Jan 11 00:33:23 volumio volumio[25610]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 11 00:33:23 volumio volumio[25610]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 11 00:33:23 volumio volumio[25610]: code: 'ECONNRESET', Jan 11 00:33:23 volumio volumio[25610]: response: undefined Jan 11 00:33:23 volumio volumio[25610]: } Jan 11 00:33:23 volumio volumio[25610]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 00:33:24 volumio sudo[26335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-11 00:32' Jan 11 00:33:24 volumio sudo[26335]: 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"