Jan 13 19:23:00 volumio volumio[13122]: info: Loading plugin "squeezelite_mc"... Jan 13 19:23:01 volumio volumio[13122]: info: Loading plugin "youtube2"... Jan 13 19:23:01 volumio nmbd[1048]: [2026/01/13 19:23:01.261213, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jan 13 19:23:01 volumio nmbd[1048]: Packet send failed to 169.254.255.255(138) ERRNO=Network is unreachable Jan 13 19:23:01 volumio volumio[13122]: info: Loading plugin "ytcr"... Jan 13 19:23:03 volumio volumio[13122]: info: Loading plugin "ytmusic"... Jan 13 19:23:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 13 19:23:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:03 volumio go-librespot[13298]: go-librespot daemon starting... Jan 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23:03-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23:03-06:00" level=debug msg="app state loaded" Jan 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23:03-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23:03-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:03 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.63.8 Jan 13 19:23:03 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:23:03 volumio avahi-daemon[664]: Registering new address record for 169.254.63.8 on eth0.IPv4. Jan 13 19:23:03 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:03 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:03 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23: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 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23: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 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23: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 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23:03-06:00" level=info msg="zeroconf server listening on port 33217" Jan 13 19:23:03 volumio volumio[13122]: info: Plugin now_playing is not enabled Jan 13 19:23:03 volumio volumio[13122]: info: Loading plugin "outputs"... Jan 13 19:23:03 volumio volumio[13122]: info: Loading plugin "albumart"... Jan 13 19:23:03 volumio volumio[13122]: info: Plugin example_plugin is not enabled Jan 13 19:23:03 volumio volumio[13122]: info: Loading plugin "inputs"... Jan 13 19:23:03 volumio volumio[13122]: info: Loading plugin "updater_comm"... Jan 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23:03-06:00" level=debug msg="obtained new client token: AADEva0yM7y0GSjLK5M4/GXOCaAw55E8oaLCnp/wy2HOeDFPDAn9IHLnxdboJPd0KR3A8aIW+4NI7p2hwJcPPOp3whuqGWv8dmNAjGZHR6GIlBjnHId3WwBeNIRB0tXSjDFX0+34tut0ICH1zcj4fFkGai8JAdv8ljvULi9dud5/CJbgT3twJ+rU1xgXHL7DqMUXCS/MJDtWNNhQ2hhftZb9oOI0iy/FvTli0wvtcpenVSis7L2ZLAVv9w==" Jan 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23:03-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:03 volumio volumio[13122]: info: Plugin mpdemulation is not enabled Jan 13 19:23:03 volumio volumio[13122]: info: Loading plugin "rest_api"... Jan 13 19:23:03 volumio volumio[13122]: info: Loading plugin "websocket"... Jan 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23:03-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:03 volumio volumio[13122]: info: Starting Socket.io Server version 1.7.4 Jan 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23:03-06:00" level=debug msg="completed challenge" Jan 13 19:23:03 volumio volumio[13122]: info: Plugin fusiondsp is not enabled Jan 13 19:23:03 volumio volumio[13122]: info: Plugin mpdoutput is not enabled Jan 13 19:23:03 volumio volumio[13122]: info: Plugin RoonBridge is not enabled Jan 13 19:23:03 volumio volumio[13122]: info: Loading plugin "podcast"... Jan 13 19:23:03 volumio go-librespot[13299]: time="2026-01-13T19:23: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 13 19:23:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:03 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.63.8 Jan 13 19:23:04 volumio volumio[13122]: info: ControllerPodcast::constructor Jan 13 19:23:04 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 19:23:04 volumio volumio[13122]: info: Loading plugin "volusonic"... Jan 13 19:23:04 volumio volumio[13323]: Forking 3 albumart workers Jan 13 19:23:04 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.63.8 Jan 13 19:23:04 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.63.8 Jan 13 19:23:04 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:23:04 volumio avahi-daemon[664]: Withdrawing address record for 169.254.63.8 on eth0. Jan 13 19:23:04 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:04 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:04 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:04 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:23:05 volumio volumio-remote-updater[14193]: [2026-01-13 19:23:05] [connect] Successful connection Jan 13 19:23:06 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 19:23:06 volumio volumio[13122]: info: Applying required configuration parameters for plugin volusonic Jan 13 19:23:06 volumio volumio[13122]: info: Loading plugin "backup_restore"... Jan 13 19:23:06 volumio volumio[13337]: Starting albumart workers Jan 13 19:23:06 volumio volumio[13339]: Starting albumart workers Jan 13 19:23:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 13 19:23:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:07 volumio volumio[13338]: Starting albumart workers Jan 13 19:23:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:07 volumio go-librespot[13383]: go-librespot daemon starting... Jan 13 19:23:07 volumio volumio[13122]: info: Applying required configuration parameters for plugin backup_restore Jan 13 19:23:07 volumio volumio[13122]: info: Plugin rpi_eeprom_config is not enabled Jan 13 19:23:07 volumio volumio[13122]: info: Plugin rpi_eeprom_updater is not enabled Jan 13 19:23:07 volumio volumio[13122]: info: Loading plugin "scheduledrestart"... Jan 13 19:23:07 volumio go-librespot[13384]: time="2026-01-13T19:23:07-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:07 volumio go-librespot[13384]: time="2026-01-13T19:23:07-06:00" level=debug msg="app state loaded" Jan 13 19:23:07 volumio go-librespot[13384]: time="2026-01-13T19:23:07-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:07 volumio go-librespot[13384]: time="2026-01-13T19:23:07-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:07 volumio volumio[13122]: info: Applying required configuration parameters for plugin scheduledrestart Jan 13 19:23:07 volumio volumio[13122]: info: Plugin Bluetoothremote is not enabled Jan 13 19:23:07 volumio volumio[13122]: info: Plugin music_services_shield is not enabled Jan 13 19:23:07 volumio volumio[13122]: info: Loading plugin "Systeminfo"... Jan 13 19:23:07 volumio go-librespot[13384]: time="2026-01-13T19:23:07-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:23:07 volumio go-librespot[13384]: time="2026-01-13T19:23:07-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 13 19:23:07 volumio go-librespot[13384]: time="2026-01-13T19:23:07-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 13 19:23:07 volumio go-librespot[13384]: time="2026-01-13T19:23:07-06:00" level=info msg="zeroconf server listening on port 32839" Jan 13 19:23:07 volumio go-librespot[13384]: time="2026-01-13T19:23:07-06:00" level=debug msg="obtained new client token: AACgwV4y2zSQ4CwjdROrZqht9SBuMXP3wrBHCtce64JoW/kgFLE7r10UfNBi3gqtNOPHpnB+HrfD7jUc7AIvYrxkZqmcSHEvk09Q2q9nKIRdOFWSmzgAkUTBkbMx/eLrtEJED6x68tHc6tdYVBBdXJS+J7tAbaYLDM/XgmvTmE5OvDMXzuw3rqW4bF7oGw3L5yN0C6wCinQ9xtjlEYOfffaz0xkJ+vmQL19vRUGWEiNQmKSt6ZjH7QXRjw==" Jan 13 19:23:08 volumio go-librespot[13384]: time="2026-01-13T19:23:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:08 volumio go-librespot[13384]: time="2026-01-13T19:23:08-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:08 volumio go-librespot[13384]: time="2026-01-13T19:23:08-06:00" level=debug msg="completed challenge" Jan 13 19:23:08 volumio go-librespot[13384]: time="2026-01-13T19:23:08-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 19:23:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:08 volumio volumio[13122]: info: Plugin peppymeterbasic is not enabled Jan 13 19:23:08 volumio volumio[13122]: info: Loading plugin "peppyspectrum"... Jan 13 19:23:08 volumio volumio[13122]: info: Loading i18n strings for locale en Jan 13 19:23:08 volumio volumio[13122]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 19:23:08 volumio volumio[13122]: Updating browse sources language Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::initPlayerControls Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:23:08 volumio volumio[13122]: Express server listening on port 3000 Jan 13 19:23:08 volumio volumio[13122]: [Metrics] WebUI: 19s 99.91ms Jan 13 19:23:08 volumio volumio[13122]: info: CoreStateMachine::resetVolumioState Jan 13 19:23:08 volumio volumio[13122]: info: CoreStateMachine::getcurrentVolume Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:08 volumio sudo[13414]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 19:23:08 volumio sudo[13414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:08 volumio sudo[13414]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:08 volumio sudo[13416]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 19:23:08 volumio sudo[13416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:08 volumio sudo[13416]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:08 volumio volumio[13122]: info: Volumio Network Manager: Network status updated: 1 Jan 13 19:23:08 volumio volumio[13122]: info: VolumeController:: Volume=100 Mute =false Jan 13 19:23:08 volumio volumio[13122]: info: CoreStateMachine::pushState Jan 13 19:23:08 volumio volumio[13122]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 13 19:23:08 volumio volumio[13122]: info: CoreCommandRouter::volumioPushState Jan 13 19:23:08 volumio volumio[13122]: info: CoreStateMachine::updateTrackBlock Jan 13 19:23:08 volumio volumio[13122]: info: CorePlayQueue::getTrackBlock Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 19:23:09 volumio volumio-remote-updater[14193]: [2026-01-13 19:23:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768353785 101 Jan 13 19:23:09 volumio volumio[13122]: 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 13 19:23:09 volumio volumio[13122]: info: Reloading queue from file Jan 13 19:23:09 volumio volumio[13122]: info: CoreStateMachine::setRepeat null single undefined Jan 13 19:23:09 volumio volumio[13122]: info: CoreStateMachine::pushState Jan 13 19:23:09 volumio volumio[13122]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioPushState Jan 13 19:23:09 volumio volumio[13122]: info: CoreStateMachine::setRandom null Jan 13 19:23:09 volumio volumio[13122]: info: CoreStateMachine::pushState Jan 13 19:23:09 volumio volumio[13122]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioPushState Jan 13 19:23:09 volumio volumio[13122]: info: Setting Device type: Raspberry PI Jan 13 19:23:09 volumio volumio[13122]: info: VolumeController:: Volume=100 Mute =false Jan 13 19:23:09 volumio volumio[13122]: info: CoreStateMachine::pushState Jan 13 19:23:09 volumio volumio[13122]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioPushState Jan 13 19:23:09 volumio volumio[13122]: info: Completed loading Core Plugins Jan 13 19:23:09 volumio volumio[13122]: info: Preparing to generate the ALSA configuration file Jan 13 19:23:09 volumio sudo[13429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 13 19:23:09 volumio sudo[13429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:09 volumio volumio[13122]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 19:23:09 volumio volumio[13122]: info: Discovery: Found device Volumio Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioGetState Jan 13 19:23:09 volumio volumio[13122]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:09 volumio volumio[13122]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 19:23:09 volumio volumio[13122]: info: Discovery: Found device Volumio Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioGetState Jan 13 19:23:09 volumio volumio[13122]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:09 volumio sudo[13429]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:09 volumio volumio[13122]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 19:23:09 volumio volumio[13122]: info: Reading ALSA contributions from plugins. Jan 13 19:23:09 volumio volumio[13122]: info: Upmpdcli Daemon Started Jan 13 19:23:09 volumio volumio[13122]: info: Asound.conf file unchanged, so no further update is needed Jan 13 19:23:09 volumio volumio[13122]: info: Output device has changed, restarting MPD Jan 13 19:23:09 volumio volumio[13122]: info: Output device has changed, restarting Shairport Sync Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:09 volumio sudo[13432]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 19:23:09 volumio sudo[13432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:09 volumio sudo[13432]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:09 volumio sudo[13434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 19:23:09 volumio sudo[13434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:09 volumio volumio[13122]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:23:09 volumio volumio[13122]: info: ___________ START PLUGINS ___________ Jan 13 19:23:09 volumio volumio[13122]: info: ControllerMpd::onStart: Initializing MPD Jan 13 19:23:09 volumio volumio[13122]: info: Creating MPD Configuration file Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:09 volumio volumio[13122]: info: [1768353789342] CoreMusicLibrary::Adding element Media Servers Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:09 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 13 19:23:09 volumio sudo[13443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 19:23:09 volumio sudo[13443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:09 volumio sudo[13444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 19:23:09 volumio sudo[13444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:09 volumio sudo[13443]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:09 volumio volumio[13122]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:09 volumio volumio[13122]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:09 volumio volumio[13122]: info: [1768353789451] CoreMusicLibrary::Adding element Last_100 Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:09 volumio volumio[13122]: info: [1768353789456] CoreMusicLibrary::Adding element Webradio Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 19:23:09 volumio volumio[13122]: info: Initializing BBC Radios Jan 13 19:23:09 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 19:23:09 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 19:23:09 volumio systemd[1]: mpd.service: Consumed 5.341s CPU time. Jan 13 19:23:09 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 19:23:09 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 19:23:09 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:09 volumio volumio[13122]: info: [1768353789540] CoreMusicLibrary::Adding element Bandcamp Discover Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:09 volumio volumio[13122]: info: [1768353789550] CoreMusicLibrary::Adding element SoundCloud Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source SoundCloud Jan 13 19:23:09 volumio volumio[13122]: info: Creating Spotify config file Jan 13 19:23:09 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:09 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 19:23:09 volumio sudo[13469]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 19:23:09 volumio sudo[13469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 19:23:09 volumio sudo[13469]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:09 volumio volumio[13122]: info: [squeezelite_mc] Starting proxy server... Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:09 volumio volumio[13122]: info: [1768353789913] CoreMusicLibrary::Adding element YouTube2 Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source SoundCloud Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source YouTube2 Jan 13 19:23:09 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.66.164 Jan 13 19:23:09 volumio avahi-daemon[664]: Registering new address record for 169.254.66.164 on eth0.IPv4. Jan 13 19:23:09 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:09 volumio volumio[13122]: info: [1768353789938] CoreMusicLibrary::Adding element YouTube Music Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source SoundCloud Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source YouTube2 Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source YouTube Music Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:09 volumio volumio[13122]: info: [1768353789955] CoreMusicLibrary::Adding element Podcast Jan 13 19:23:09 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source SoundCloud Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source YouTube2 Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source YouTube Music Jan 13 19:23:09 volumio volumio[13122]: Cannot find translation for source Podcast Jan 13 19:23:09 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:09 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:09 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:09 volumio volumio[13122]: info: Loading i18n strings for locale en Jan 13 19:23:10 volumio volumio[13122]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 19:23:10 volumio volumio[13122]: Updating browse sources language Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source SoundCloud Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source YouTube2 Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source YouTube Music Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source Podcast Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source SoundCloud Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source YouTube2 Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source YouTube Music Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source Podcast Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:10 volumio volumio[13122]: info: [1768353790010] CoreMusicLibrary::Adding element Volusonic Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source SoundCloud Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source YouTube2 Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source YouTube Music Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source Podcast Jan 13 19:23:10 volumio volumio[13122]: Cannot find translation for source Volusonic Jan 13 19:23:10 volumio volumio[13122]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 13 19:23:10 volumio volumio[13122]: info: Volumio Calling Home Jan 13 19:23:10 volumio volumio[13122]: info: [squeezelite_mc] Proxy server started on port 41053 Jan 13 19:23:10 volumio volumio[13122]: info: Preparing to generate the ALSA configuration file Jan 13 19:23:10 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.66.164 Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 19:23:10 volumio volumio[13122]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 19:23:10 volumio volumio[13122]: info: Reading ALSA contributions from plugins. Jan 13 19:23:10 volumio volumio[13122]: info: MPD Permissions set Jan 13 19:23:10 volumio volumio[13122]: info: MPD Permissions set Jan 13 19:23:10 volumio volumio[13122]: info: Spotify config file written Jan 13 19:23:10 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.66.164 Jan 13 19:23:10 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.66.164 Jan 13 19:23:10 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:23:10 volumio avahi-daemon[664]: Withdrawing address record for 169.254.66.164 on eth0. Jan 13 19:23:10 volumio sudo[13495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 13 19:23:10 volumio sudo[13495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:10 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 19:23:10 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:10 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:10 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:10 volumio volumio[13122]: 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 13 19:23:10 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:23:10 volumio volumio[13122]: info: VolumeController:: Volume=100 Mute =false Jan 13 19:23:10 volumio volumio[13122]: info: CoreStateMachine::pushState Jan 13 19:23:10 volumio volumio[13122]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::volumioPushState Jan 13 19:23:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:10 volumio volumio[13122]: info: [squeezelite_mc] Server discovery started Jan 13 19:23:10 volumio volumio[13122]: info: [squeezelite_mc] Player finder started Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:10 volumio go-librespot[13514]: go-librespot daemon starting... Jan 13 19:23:10 volumio sudo[13495]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio go-librespot[13519]: time="2026-01-13T19:23:10-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:10 volumio go-librespot[13519]: time="2026-01-13T19:23:10-06:00" level=debug msg="app state loaded" Jan 13 19:23:10 volumio go-librespot[13519]: time="2026-01-13T19:23:10-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:10 volumio go-librespot[13519]: time="2026-01-13T19:23:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:10 volumio volumio[13122]: info: No need to fix Spotify hosts Jan 13 19:23:10 volumio volumio[13122]: 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 13 19:23:10 volumio volumio[13122]: info: Volumio called home Jan 13 19:23:10 volumio volumio[13122]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 13 19:23:10 volumio volumio[13122]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 13 19:23:10 volumio volumio[13122]: 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 13 19:23:10 volumio go-librespot[13519]: time="2026-01-13T19:23:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:23:10 volumio go-librespot[13519]: time="2026-01-13T19:23:10-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 13 19:23:10 volumio go-librespot[13519]: time="2026-01-13T19:23:10-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 13 19:23:10 volumio go-librespot[13519]: time="2026-01-13T19:23:10-06:00" level=info msg="zeroconf server listening on port 38261" Jan 13 19:23:10 volumio volumio[13122]: info: Starting Shairport Sync Jan 13 19:23:11 volumio volumio[13122]: info: Starting Shairport Sync Jan 13 19:23:11 volumio volumio[13122]: info: Starting Shairport Sync Jan 13 19:23:11 volumio sudo[13539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:23:11 volumio sudo[13537]: 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 13 19:23:11 volumio sudo[13537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:11 volumio sudo[13539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:11 volumio sudo[13537]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:11 volumio volumio[13122]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 19:23:11 volumio volumio[13122]: SPOTIFY: BQAEztpwdChZdZpic6wISCng8V44qriarO80QqNirC8k_0VbGXaV4qvbgkKgt4oW2Tv4UMCf4K3gXGxHWjl8sJNlCpspU1iJuujtA3NZbajy2tKZ_8ApHmm9Mn758iaVptuwiHCc_lPzSRYrxkidAoptT7oudMjplYc2oKlo-SRKkkzWpcgZ1ozyAGVtxH8tkmpVgMtsy1eTGSHGFSsNsKwK3NGsjmBRdXwhQh0 Jan 13 19:23:11 volumio volumio[13122]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 19:23:11 volumio volumio[13122]: info: New Spotify access token = BQAEztpwdChZdZpic6wISCng8V44qriarO80QqNirC8k_0VbGXaV4qvbgkKgt4oW2Tv4UMCf4K3gXGxHWjl8sJNlCpspU1iJuujtA3NZbajy2tKZ_8ApHmm9Mn758iaVptuwiHCc_lPzSRYrxkidAoptT7oudMjplYc2oKlo-SRKkkzWpcgZ1ozyAGVtxH8tkmpVgMtsy1eTGSHGFSsNsKwK3NGsjmBRdXwhQh0 Jan 13 19:23:11 volumio sudo[13544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:23:11 volumio sudo[13544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:11 volumio volumio[13122]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 13 19:23:11 volumio go-librespot[13519]: time="2026-01-13T19:23:11-06:00" level=debug msg="obtained new client token: AAC/499rYC4o3JtpbmWC8hNdVqHkwYO2nNbOksP4N5VnHjLjHq5NzSOw6O3rrO5ETF+f3LKiL8yLEa2pHDbJjptRk/vRWRlLtYQZ7q11/5S6IZ/ZjIBf4CxGcOAq6ruPn+kRF0bXORcs8Ice6OCUaRRZgALg/f4cW+PMidalR80wywDAOCjFSS6NkBoHlqYzMGhRMYR6B8UM1hkfaOBrNhik0vUsSVf2WqjRlxk9/OE49IBbYfHi9k8=" Jan 13 19:23:11 volumio sudo[13542]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:23:11 volumio sudo[13542]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 19:23:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 19:23:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:11 volumio systemd[1]: shairport-sync.service: Consumed 1.941s CPU time. Jan 13 19:23:11 volumio go-librespot[13519]: time="2026-01-13T19:23:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:11 volumio go-librespot[13519]: time="2026-01-13T19:23:11-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:11 volumio go-librespot[13519]: time="2026-01-13T19:23:11-06:00" level=debug msg="completed challenge" Jan 13 19:23:11 volumio volumio[13122]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 13 19:23:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:11 volumio sudo[13539]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:11 volumio go-librespot[13519]: time="2026-01-13T19:23:11-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 19:23:11 volumio volumio[13122]: info: Asound.conf file unchanged, so no further update is needed Jan 13 19:23:11 volumio volumio[13122]: info: Output device has changed, restarting MPD Jan 13 19:23:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:11 volumio sudo[13552]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 13 19:23:11 volumio sudo[13552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 19:23:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 19:23:11 volumio volumio[13122]: info: Output device has changed, restarting Shairport Sync Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:11 volumio sudo[13544]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:11 volumio sudo[13552]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:11 volumio sudo[13555]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 19:23:11 volumio sudo[13555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:11 volumio sudo[13542]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:11 volumio sudo[13555]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:11 volumio sudo[13557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 19:23:11 volumio sudo[13557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:11 volumio volumio[13122]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:23:11 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 19:23:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 19:23:11 volumio systemd[1]: mpd.service: Consumed 1.721s CPU time. Jan 13 19:23:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 19:23:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 19:23:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 19:23:11 volumio volumio[13122]: info: MPD Permissions set Jan 13 19:23:11 volumio volumio[13122]: info: Shairport-Sync Started Jan 13 19:23:11 volumio volumio[13122]: Error adding Membership: Error: addMembership EINVAL Jan 13 19:23:11 volumio volumio[13122]: info: Shairport-Sync Started Jan 13 19:23:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 19:23:11 volumio volumio[13122]: 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 13 19:23:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 19:23:11 volumio volumio[13122]: info: Shairport-Sync Started Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:11 volumio sudo[13586]: 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 13 19:23:11 volumio sudo[13586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:11 volumio volumio[13122]: info: CoreCommandRouter::volumioGetState Jan 13 19:23:11 volumio volumio[13122]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:11 volumio sudo[13586]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:11 volumio volumio[13122]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 13 19:23:11 volumio volumio[13122]: info: Starting Shairport Sync Jan 13 19:23:11 volumio sudo[13594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 13 19:23:11 volumio sudo[13594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:11 volumio volumio[13122]: 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 13 19:23:11 volumio volumio[13122]: info: Spotify Successfully logged in Jan 13 19:23:12 volumio volumio[13122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:12 volumio volumio[13122]: info: [1768353792020] CoreMusicLibrary::Adding element Spotify Jan 13 19:23:12 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:12 volumio volumio[13122]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:12 volumio volumio[13122]: Cannot find translation for source SoundCloud Jan 13 19:23:12 volumio systemd[1]: Reloading. Jan 13 19:23:12 volumio sudo[13584]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 19:23:12 volumio sudo[13584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 19:23:12 volumio volumio[13122]: Cannot find translation for source YouTube2 Jan 13 19:23:12 volumio volumio[13122]: Cannot find translation for source YouTube Music Jan 13 19:23:12 volumio volumio[13122]: Cannot find translation for source Podcast Jan 13 19:23:12 volumio volumio[13122]: Cannot find translation for source Volusonic Jan 13 19:23:12 volumio volumio[13122]: Cannot find translation for source Spotify Jan 13 19:23:12 volumio sudo[13584]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:12 volumio sudo[13596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:23:12 volumio sudo[13596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:12 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 19:23:12 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:12 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:12 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:12 volumio volumio[13122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:23:13 volumio volumio[13122]: info: go-librespot daemon successfully initialized Jan 13 19:23:14 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 13 19:23:14 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 13 19:23:14 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.78.161 Jan 13 19:23:14 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:23:14 volumio avahi-daemon[664]: Registering new address record for 169.254.78.161 on eth0.IPv4. Jan 13 19:23:15 volumio sudo[13594]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:15 volumio volumio[13122]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 13 19:23:15 volumio sudo[13649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:15 volumio sudo[13649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:15 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:15 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:15 volumio sudo[13649]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:15 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:15 volumio volumio[13122]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 13 19:23:15 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.78.161 Jan 13 19:23:15 volumio sudo[13653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 13 19:23:15 volumio sudo[13653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:15 volumio go-librespot[13651]: go-librespot daemon starting... Jan 13 19:23:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 19:23:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 19:23:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:15 volumio systemd[1]: shairport-sync.service: Consumed 1.486s CPU time. Jan 13 19:23:15 volumio go-librespot[13655]: time="2026-01-13T19:23:15-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:15 volumio go-librespot[13655]: time="2026-01-13T19:23:15-06:00" level=debug msg="app state loaded" Jan 13 19:23:15 volumio go-librespot[13655]: time="2026-01-13T19:23:15-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:15 volumio go-librespot[13655]: time="2026-01-13T19:23:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:15 volumio sudo[13596]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:15 volumio volumio[13122]: info: Shairport-Sync Started Jan 13 19:23:15 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 13 19:23:15 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.78.161 Jan 13 19:23:15 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.78.161 Jan 13 19:23:15 volumio avahi-daemon[664]: Withdrawing address record for 169.254.78.161 on eth0. Jan 13 19:23:15 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:23:15 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 13 19:23:15 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 13 19:23:15 volumio sudo[13653]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:15 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:15 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:15 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:15 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:23:15 volumio go-librespot[13655]: time="2026-01-13T19:23:15-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 19:23:15 volumio go-librespot[13655]: time="2026-01-13T19:23:15-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 13 19:23:15 volumio go-librespot[13655]: time="2026-01-13T19:23:15-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 13 19:23:15 volumio go-librespot[13655]: time="2026-01-13T19:23:15-06:00" level=info msg="zeroconf server listening on port 42423" Jan 13 19:23:16 volumio go-librespot[13655]: time="2026-01-13T19:23:16-06:00" level=debug msg="obtained new client token: AAA0jwXe4lTrtG+o5LOrjot8yusScOei0S0MyI3ceBLkn9qapNwwmo2WKxZAnjncBf4O0C+liyAHqtd0TUYrz6bbyK8hydSvETeFx/4PE7KE9AOhl43zACN/T8dTKYtZQBcDwGuzMvbTqaYsnSfJGCW/iU+lclddeILLCSmOABQ9g/nZOjxf7YDVkRXNI9zy1agcGT9xEsb21vKDkkKVSA+eaWF8VVbB/DcrchDvZN4SHB274bIf5/KDPA==" Jan 13 19:23:16 volumio go-librespot[13655]: time="2026-01-13T19:23:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:16 volumio go-librespot[13655]: time="2026-01-13T19:23:16-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:16 volumio go-librespot[13655]: time="2026-01-13T19:23:16-06:00" level=debug msg="completed challenge" Jan 13 19:23:16 volumio go-librespot[13655]: time="2026-01-13T19:23:16-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 19:23:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:16 volumio volumio[13122]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:16 volumio sudo[13695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:16 volumio sudo[13695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:16 volumio sudo[13695]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:16 volumio volumio[13122]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 13 19:23:16 volumio sudo[13700]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 13 19:23:16 volumio sudo[13700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:16 volumio sudo[13700]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:16 volumio volumio[13122]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 13 19:23:16 volumio sudo[13703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 13 19:23:16 volumio sudo[13703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:16 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 13 19:23:16 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 13 19:23:16 volumio sudo[13703]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:16 volumio volumio[13122]: info: Initializing connection to go-librespot Websocket Jan 13 19:23:16 volumio volumio[13122]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 19:23:17 volumio volumio[13122]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:17 volumio sudo[13710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:17 volumio sudo[13710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:17 volumio sudo[13710]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:17 volumio volumio[13122]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:17 volumio sudo[13713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:17 volumio sudo[13713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:17 volumio sudo[13713]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:18 volumio volumio[13122]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:18 volumio sudo[13716]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:18 volumio sudo[13716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:18 volumio mpd[13647]: 2026-01-13T19:23:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 13 19:23:18 volumio sudo[13716]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:18 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 13 19:23:18 volumio sudo[13434]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:18 volumio sudo[13557]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:18 volumio sudo[13444]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:18 volumio volumio[13122]: error: MPD error: The expression evaluated to a falsy value: Jan 13 19:23:18 volumio volumio[13122]: assert.ok(self.idling) Jan 13 19:23:18 volumio volumio[13122]: error: The expression evaluated to a falsy value: Jan 13 19:23:18 volumio volumio[13122]: assert.ok(self.idling) Jan 13 19:23:18 volumio volumio[13122]: error: MPD error: The expression evaluated to a falsy value: Jan 13 19:23:18 volumio volumio[13122]: assert.ok(self.idling) Jan 13 19:23:18 volumio volumio[13122]: error: The expression evaluated to a falsy value: Jan 13 19:23:18 volumio volumio[13122]: assert.ok(self.idling) Jan 13 19:23:18 volumio volumio[13122]: info: MPD running with PID13647 Jan 13 19:23:18 volumio volumio[13122]: ,establishing connection Jan 13 19:23:18 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 19:23:18 volumio volumio[13122]: error: updateQueue error: null Jan 13 19:23:18 volumio volumio[13122]: error: updateQueue error: null Jan 13 19:23:18 volumio volumio[13122]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:18 volumio sudo[13724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:18 volumio sudo[13724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:19 volumio sudo[13724]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 13 19:23:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:19 volumio go-librespot[13726]: go-librespot daemon starting... Jan 13 19:23:19 volumio volumio[13122]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=debug msg="app state loaded" Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:19 volumio sudo[13734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:19 volumio sudo[13734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:19 volumio sudo[13734]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:19 volumio volumio[13122]: info: Completed starting Core Plugins Jan 13 19:23:19 volumio volumio[13122]: info: ------------------------------------------- Jan 13 19:23:19 volumio volumio[13122]: info: ----- MyVolumio plugins startup ---- Jan 13 19:23:19 volumio volumio[13122]: info: ------------------------------------------- Jan 13 19:23:19 volumio volumio[13122]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=info msg="zeroconf server listening on port 35571" Jan 13 19:23:19 volumio volumio[13122]: info: Initializing connection to go-librespot Websocket Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=debug msg="new websocket client" Jan 13 19:23:19 volumio volumio[13122]: info: Connection to go-librespot Websocket established Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=debug msg="obtained new client token: AABGg3wP/P3lBb8oT07VNWthytnADP80CgJTFz6y7KcSQYB9v54wL4i35ps32PVrMEXlTPm897Bl94/RfDCsXEHSAV3kpiyxwXKpwz+Os1XSR+Tnw1/HybOJb2b6YYfaIwrYArzlBGgx2yh9zvV+diX6MFAe55AV/VxUbdokFpPndkjaGfIZX64pKcMUpcgh+XzYooahxUm4k13wqaUKFWq/kOoJzepZADKcInBzBvAxsFOAxoPNbYHIjg==" Jan 13 19:23:19 volumio go-librespot[13727]: time="2026-01-13T19:23:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:20 volumio go-librespot[13727]: time="2026-01-13T19:23:20-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:20 volumio go-librespot[13727]: time="2026-01-13T19:23:20-06:00" level=debug msg="completed challenge" Jan 13 19:23:20 volumio go-librespot[13727]: time="2026-01-13T19:23: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 13 19:23:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:20 volumio volumio[13122]: info: Connection to go-librespot Websocket closed Jan 13 19:23:20 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.169.186 Jan 13 19:23:20 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:23:20 volumio avahi-daemon[664]: Registering new address record for 169.254.169.186 on eth0.IPv4. Jan 13 19:23:20 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:20 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:20 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:20 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.169.186 Jan 13 19:23:21 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.169.186 Jan 13 19:23:21 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.169.186 Jan 13 19:23:21 volumio avahi-daemon[664]: Withdrawing address record for 169.254.169.186 on eth0. Jan 13 19:23:21 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:23:21 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:23:21 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:21 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:21 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:21 volumio sudo[13770]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 19:23:21 volumio sudo[13770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:21 volumio sudo[13772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 19:23:21 volumio sudo[13772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:21 volumio sudo[13774]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 19:23:21 volumio sudo[13774]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:21 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 13 19:23:21 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 13 19:23:21 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 13 19:23:21 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 13 19:23:21 volumio sudo[13774]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:21 volumio sudo[13770]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:21 volumio sudo[13772]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:21 volumio mpd_monitor.sh[13778]: MPD Monitor Service: Starting MPD Monitor Service Jan 13 19:23:21 volumio volumio[13122]: info: Successfully started MPD Monitor Jan 13 19:23:21 volumio volumio[13122]: info: Successfully started MPD Monitor Jan 13 19:23:21 volumio volumio[13122]: info: Successfully started MPD Monitor Jan 13 19:23:22 volumio volumio[13122]: info: Getting Spotify volume Jan 13 19:23:22 volumio volumio[13122]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 19:23:22 volumio volumio[13122]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 19:23:22 volumio volumio[13122]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 13 19:23:22 volumio volumio[13122]: errno: -111, Jan 13 19:23:22 volumio volumio[13122]: code: 'ECONNREFUSED', Jan 13 19:23:22 volumio volumio[13122]: syscall: 'connect', Jan 13 19:23:22 volumio volumio[13122]: address: '127.0.0.1', Jan 13 19:23:22 volumio volumio[13122]: port: 9879, Jan 13 19:23:22 volumio volumio[13122]: response: undefined Jan 13 19:23:22 volumio volumio[13122]: } Jan 13 19:23:22 volumio volumio[13122]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 19:23:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 13 19:23:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:23 volumio go-librespot[13808]: go-librespot daemon starting... Jan 13 19:23:23 volumio go-librespot[13809]: time="2026-01-13T19:23:23-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:23 volumio go-librespot[13809]: time="2026-01-13T19:23:23-06:00" level=debug msg="app state loaded" Jan 13 19:23:23 volumio go-librespot[13809]: time="2026-01-13T19:23:23-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:23 volumio go-librespot[13809]: time="2026-01-13T19:23:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:23 volumio sudo[13819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-13 19:22' Jan 13 19:23:23 volumio sudo[13819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:23 volumio go-librespot[13809]: time="2026-01-13T19:23:23-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:23:23 volumio go-librespot[13809]: time="2026-01-13T19:23:23-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 13 19:23:23 volumio go-librespot[13809]: time="2026-01-13T19:23:23-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 13 19:23:23 volumio go-librespot[13809]: time="2026-01-13T19:23:23-06:00" level=info msg="zeroconf server listening on port 41999" Jan 13 19:23:23 volumio sudo[13819]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:24 volumio volumio-remote-updater[14193]: [2026-01-13 19:23:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 13 19:23:24 volumio volumio-remote-updater[14193]: [2026-01-13 19:23:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 13 19:23:24 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:24 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 13 19:23:24 volumio systemd[1]: volumio.service: Consumed 44.598s CPU time. Jan 13 19:23:24 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 13 19:23:24 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 13 19:23:24 volumio go-librespot[13809]: time="2026-01-13T19:23:24-06:00" level=debug msg="obtained new client token: AAAAFF3Ss5oA+yUNeB9cCxEdp7IUKqAsqYe2rfhHT32xfJmE0ovGybDo1D+AzaBP5/Zof9smyNZIrEZCWBIlmhMZJDktM3jKIgrbWE4P3nWyjQf/aZ8DG1+RkmbZMNpwhV05nQne/y6waS5fD+LPlfIAR4oDVfAeUUYix1i5TXZIbrNEEmWEXlHBsFICxugF0ws0YI4SOiB/TYYETOlw9aWrsbWpqYhDjClw497CjZyzM7nKWTMNzAW60Q==" Jan 13 19:23:24 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 23518. Jan 13 19:23:24 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 13 19:23:24 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 13 19:23:24 volumio systemd[1]: volumio.service: Consumed 44.598s CPU time. Jan 13 19:23:24 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 13 19:23:24 volumio go-librespot[13809]: time="2026-01-13T19:23:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:24 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 13 19:23:24 volumio go-librespot[13809]: time="2026-01-13T19:23:24-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:24 volumio go-librespot[13809]: time="2026-01-13T19:23:24-06:00" level=debug msg="completed challenge" Jan 13 19:23:24 volumio go-librespot[13809]: time="2026-01-13T19:23:24-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 19:23:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:26 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.153.250 Jan 13 19:23:26 volumio avahi-daemon[664]: Registering new address record for 169.254.153.250 on eth0.IPv4. Jan 13 19:23:26 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:23:26 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:26 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:26 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:26 volumio volumio[13834]: info: ------------------------------------------- Jan 13 19:23:26 volumio volumio[13834]: info: ----- Volumio3 ---- Jan 13 19:23:26 volumio volumio[13834]: info: ------------------------------------------- Jan 13 19:23:26 volumio volumio[13834]: info: ----- System startup ---- Jan 13 19:23:26 volumio volumio[13834]: info: ------------------------------------------- Jan 13 19:23:26 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.153.250 Jan 13 19:23:26 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.153.250 Jan 13 19:23:26 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.153.250 Jan 13 19:23:26 volumio avahi-daemon[664]: Withdrawing address record for 169.254.153.250 on eth0. Jan 13 19:23:26 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:23:27 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:27 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:27 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:27 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:23:27 volumio volumio[13834]: info: MYVOLUMIO Environment detected Jan 13 19:23:27 volumio volumio[13834]: info: Plugin folders cleanup Jan 13 19:23:27 volumio volumio[13834]: info: Scanning into folder /volumio/app/plugins/ Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category audio_interface Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category miscellanea Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category music_service Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category plugins.json Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category system_controller Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category user_interface Jan 13 19:23:27 volumio volumio[13834]: info: Scanning into folder /data/plugins/ Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category audio_interface Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category music_service Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category system_controller Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category system_hardware Jan 13 19:23:27 volumio volumio[13834]: info: Scanning category user_interface Jan 13 19:23:27 volumio volumio[13834]: info: Plugin folders cleanup completed Jan 13 19:23:27 volumio volumio[13834]: info: ------------------------------------------- Jan 13 19:23:27 volumio volumio[13834]: info: ----- Core plugins startup ---- Jan 13 19:23:27 volumio volumio[13834]: info: ------------------------------------------- Jan 13 19:23:27 volumio volumio[13834]: info: Loading plugins from folder /volumio/app/plugins/ Jan 13 19:23:27 volumio volumio[13834]: info: Adding plugin upnp to MyMusic Plugins Jan 13 19:23:27 volumio volumio[13834]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 13 19:23:27 volumio volumio[13834]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 13 19:23:27 volumio volumio[13834]: info: Loading plugins from folder /data/plugins/ Jan 13 19:23:27 volumio volumio[13834]: info: Loading plugin "system"... Jan 13 19:23:27 volumio volumio[13834]: info: Loading plugin "appearance"... Jan 13 19:23:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 13 19:23:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:27 volumio go-librespot[13893]: go-librespot daemon starting... Jan 13 19:23:27 volumio go-librespot[13894]: time="2026-01-13T19:23:27-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:27 volumio go-librespot[13894]: time="2026-01-13T19:23:27-06:00" level=debug msg="app state loaded" Jan 13 19:23:27 volumio go-librespot[13894]: time="2026-01-13T19:23:27-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:27 volumio go-librespot[13894]: time="2026-01-13T19:23:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:28 volumio go-librespot[13894]: time="2026-01-13T19:23: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:23:28 volumio go-librespot[13894]: time="2026-01-13T19:23:28-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 13 19:23:28 volumio go-librespot[13894]: time="2026-01-13T19:23:28-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 13 19:23:28 volumio go-librespot[13894]: time="2026-01-13T19:23:28-06:00" level=info msg="zeroconf server listening on port 36245" Jan 13 19:23:28 volumio go-librespot[13894]: time="2026-01-13T19:23:28-06:00" level=debug msg="obtained new client token: AADPqEbm4/mEzbAJX5Utdn1zZ58Ea+FDQ3IXKOhzbYLPpQIct82aF7IfXYXso/Xnge/tApEH1Psd2boNsC9Ah295WHOP3ImrmoXznohXHimmfN//V4vKouJLVgMzXvUkkQnwW43o0xzcXWEdZiWu8QZKxY1XkNe2YaK+fVgOVC4VWslOAFOajNqmZpTI1FOicJQzQPfE0Z74rYEijEB/XPhs8UcU/wwRvBZ9paogXJGKl4wtRk4cvOk=" Jan 13 19:23:28 volumio go-librespot[13894]: time="2026-01-13T19:23:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:28 volumio go-librespot[13894]: time="2026-01-13T19:23:28-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:28 volumio go-librespot[13894]: time="2026-01-13T19:23:28-06:00" level=debug msg="completed challenge" Jan 13 19:23:28 volumio go-librespot[13894]: time="2026-01-13T19:23:28-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 19:23:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:28 volumio volumio[13834]: info: Loading plugin "network"... Jan 13 19:23:28 volumio volumio[13834]: info: Refreshing Cached IP Addresses Jan 13 19:23:28 volumio sudo[13902]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 19:23:28 volumio sudo[13902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:28 volumio sudo[13904]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 19:23:28 volumio sudo[13902]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:28 volumio sudo[13904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:28 volumio sudo[13904]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:28 volumio volumio[13834]: info: Loading plugin "services"... Jan 13 19:23:28 volumio volumio[13834]: info: Loading plugin "alsa_controller"... Jan 13 19:23:28 volumio sudo[13913]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 13 19:23:28 volumio sudo[13913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:28 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 19:23:28 volumio volumio[13834]: info: Loading plugin "wizard"... Jan 13 19:23:28 volumio volumio[13834]: info: Loading plugin "networkfs"... Jan 13 19:23:28 volumio volumio[13834]: info: Starting Udev Watcher for removable devices Jan 13 19:23:28 volumio volumio[13834]: info: Ignoring mount for partition: boot Jan 13 19:23:28 volumio volumio[13834]: info: Ignoring mount for partition: volumio Jan 13 19:23:28 volumio volumio[13834]: info: Ignoring mount for partition: volumio_data Jan 13 19:23:28 volumio volumio[13834]: info: Mounting Device Wikipedia Jan 13 19:23:28 volumio sudo[13941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 13 19:23:28 volumio sudo[13941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:28 volumio sudo[13941]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:28 volumio volumio[13834]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 13 19:23:28 volumio volumio[13834]: dmesg(1) may have more information after failed mount system call. Jan 13 19:23:28 volumio volumio[13834]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 13 19:23:28 volumio volumio[13834]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 13 19:23:28 volumio volumio[13834]: dmesg(1) may have more information after failed mount system call. Jan 13 19:23:28 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 19:23:28 volumio volumio[13834]: info: Loading plugin "volumio_command_line_client"... Jan 13 19:23:28 volumio volumio[13834]: info: Loading plugin "upnp"... Jan 13 19:23:28 volumio volumio[13834]: info: [1768353808986] Starting Upmpd Daemon Jan 13 19:23:28 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 19:23:28 volumio volumio[13834]: info: Loading plugin "my_music"... Jan 13 19:23:29 volumio volumio[13834]: info: Loading plugin "mpd"... Jan 13 19:23:29 volumio volumio-remote-updater[14193]: [2026-01-13 19:23:29] [connect] Successful connection Jan 13 19:23:29 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 19:23:29 volumio sudo[13913]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:29 volumio volumio[13834]: info: Loading plugin "upnp_browser"... Jan 13 19:23:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 13 19:23:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:31 volumio go-librespot[13944]: go-librespot daemon starting... Jan 13 19:23:31 volumio go-librespot[13945]: time="2026-01-13T19:23:31-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:31 volumio go-librespot[13945]: time="2026-01-13T19:23:31-06:00" level=debug msg="app state loaded" Jan 13 19:23:31 volumio go-librespot[13945]: time="2026-01-13T19:23:31-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:31 volumio go-librespot[13945]: time="2026-01-13T19:23:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:32 volumio go-librespot[13945]: time="2026-01-13T19:23:32-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:23:32 volumio go-librespot[13945]: time="2026-01-13T19:23:32-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 13 19:23:32 volumio go-librespot[13945]: time="2026-01-13T19:23:32-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 13 19:23:32 volumio go-librespot[13945]: time="2026-01-13T19:23:32-06:00" level=info msg="zeroconf server listening on port 36675" Jan 13 19:23:32 volumio go-librespot[13945]: time="2026-01-13T19:23:32-06:00" level=debug msg="obtained new client token: AACO65jlayDT+FoBP0NKvFq35DMPhMrPrhiUushUDn6PQf1UDcFjdyyX3HlYLcGZPJgjBl7yzWk21NtbTfo+ELN/bnFkv/minDEI/h/ZZiisaK5r4u7iSMUf9QC8qHI8TcDTIPGp52y3fU8usMAwK+pcKiRmElak0yTz+fiU0AjUvxBcaAmI9jJyHcFG3W/7kQKEMZbJsqFRA7qblLehF7InscQMLHqggvt/0tO3+dP1ib7jA+pnW0s=" Jan 13 19:23:32 volumio volumio[13834]: info: Loading plugin "alarm-clock"... Jan 13 19:23:32 volumio go-librespot[13945]: time="2026-01-13T19:23:32-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:32 volumio go-librespot[13945]: time="2026-01-13T19:23:32-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:32 volumio go-librespot[13945]: time="2026-01-13T19:23:32-06:00" level=debug msg="completed challenge" Jan 13 19:23:32 volumio go-librespot[13945]: time="2026-01-13T19:23:32-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 19:23:32 volumio volumio[13834]: info: Loading plugin "airplay_emulation"... Jan 13 19:23:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:32 volumio volumio[13834]: info: Starting Shairport Sync Jan 13 19:23:32 volumio volumio[13834]: info: Loading plugin "last_100"... Jan 13 19:23:32 volumio volumio[13834]: info: Loading plugin "webradio"... Jan 13 19:23:32 volumio volumio[13834]: info: Loading plugin "i2s_dacs"... Jan 13 19:23:32 volumio volumio[13834]: info: I2S DAC not set, start Auto-detection Jan 13 19:23:32 volumio volumio[13834]: info: Loading plugin "volumiodiscovery"... Jan 13 19:23:32 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.110.39 Jan 13 19:23:32 volumio avahi-daemon[664]: Registering new address record for 169.254.110.39 on eth0.IPv4. Jan 13 19:23:32 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:23:32 volumio volumio[13834]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 13 19:23:32 volumio volumio[13834]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 19:23:32 volumio volumio[13834]: *** WARNING *** For more information see Jan 13 19:23:32 volumio volumio[13834]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 13 19:23:32 volumio volumio[13834]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 19:23:32 volumio volumio[13834]: *** WARNING *** For more information see Jan 13 19:23:32 volumio node[13834]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 13 19:23:32 volumio node[13834]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 19:23:32 volumio node[13834]: *** WARNING *** For more information see Jan 13 19:23:32 volumio node[13834]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 13 19:23:32 volumio node[13834]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 19:23:32 volumio node[13834]: *** WARNING *** For more information see Jan 13 19:23:32 volumio volumio[13834]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 13 19:23:32 volumio volumio[13834]: info: Discovery: Started advertising with name: Volumio Jan 13 19:23:32 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:32 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:32 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:32 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 19:23:32 volumio volumio[13834]: info: Loading plugin "bandcamp"... Jan 13 19:23:33 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.110.39 Jan 13 19:23:33 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.110.39 Jan 13 19:23:33 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.110.39 Jan 13 19:23:33 volumio avahi-daemon[664]: Withdrawing address record for 169.254.110.39 on eth0. Jan 13 19:23:33 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:23:33 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:33 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:33 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:23:33 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:33 volumio volumio[13834]: info: Plugin calmradio is not enabled Jan 13 19:23:33 volumio volumio[13834]: info: Loading plugin "soundcloud"... Jan 13 19:23:34 volumio volumio[13834]: info: Loading plugin "spop"... Jan 13 19:23:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 13 19:23:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:35 volumio go-librespot[13986]: go-librespot daemon starting... Jan 13 19:23:35 volumio go-librespot[13987]: time="2026-01-13T19:23:35-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:35 volumio go-librespot[13987]: time="2026-01-13T19:23:35-06:00" level=debug msg="app state loaded" Jan 13 19:23:35 volumio go-librespot[13987]: time="2026-01-13T19:23:35-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:35 volumio go-librespot[13987]: time="2026-01-13T19:23:35-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:36 volumio go-librespot[13987]: time="2026-01-13T19:23: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:23:36 volumio go-librespot[13987]: time="2026-01-13T19:23:36-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 13 19:23:36 volumio go-librespot[13987]: time="2026-01-13T19:23:36-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 13 19:23:36 volumio go-librespot[13987]: time="2026-01-13T19:23:36-06:00" level=info msg="zeroconf server listening on port 44677" Jan 13 19:23:36 volumio go-librespot[13987]: time="2026-01-13T19:23:36-06:00" level=debug msg="obtained new client token: AAA0YI9TNSOTdNOTgHpmyE0j4K070wzxhfzJ6rcb8lYXtBjDhyjbt1DS21q7Ye++pnTvUwUjODmyosZT/hJQsmjIQ1Qm2U7z6mM15WUOApU7ZLTStFy0E/5+MYLAtOTmsNO+UcxyBrdJ2VHw26BGfKAISvmBIUV0S9+DO2s7IC5E6f8bK7Zaas9YNlbBCK0uuCILWZzCFQJlkJRFXE+BY+9q3Wa5ZvqJa21HAqlbjXOsa4ypsGL0TqM=" Jan 13 19:23:36 volumio go-librespot[13987]: time="2026-01-13T19:23:36-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Jan 13 19:23:36 volumio go-librespot[13987]: time="2026-01-13T19:23:36-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Jan 13 19:23:36 volumio volumio[13834]: info: Loading plugin "squeezelite_mc"... Jan 13 19:23:36 volumio go-librespot[13987]: time="2026-01-13T19:23:36-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:36 volumio go-librespot[13987]: time="2026-01-13T19:23:36-06:00" level=debug msg="completed challenge" Jan 13 19:23:36 volumio go-librespot[13987]: time="2026-01-13T19:23: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 13 19:23:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:37 volumio volumio[13834]: info: Loading plugin "youtube2"... Jan 13 19:23:38 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.222.87 Jan 13 19:23:38 volumio avahi-daemon[664]: Registering new address record for 169.254.222.87 on eth0.IPv4. Jan 13 19:23:38 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:23:38 volumio volumio[13834]: info: Loading plugin "ytcr"... Jan 13 19:23:38 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:38 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:38 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:38 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.222.87 Jan 13 19:23:39 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.222.87 Jan 13 19:23:39 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.222.87 Jan 13 19:23:39 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:23:39 volumio avahi-daemon[664]: Withdrawing address record for 169.254.222.87 on eth0. Jan 13 19:23:39 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:23:39 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:39 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:39 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:39 volumio volumio[13834]: info: Loading plugin "ytmusic"... Jan 13 19:23:39 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 19:23:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 13 19:23:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:39 volumio go-librespot[14042]: go-librespot daemon starting... Jan 13 19:23:39 volumio go-librespot[14043]: time="2026-01-13T19:23:39-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:39 volumio go-librespot[14043]: time="2026-01-13T19:23:39-06:00" level=debug msg="app state loaded" Jan 13 19:23:39 volumio go-librespot[14043]: time="2026-01-13T19:23:39-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:39 volumio go-librespot[14043]: time="2026-01-13T19:23:39-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:39 volumio volumio[13834]: info: Plugin now_playing is not enabled Jan 13 19:23:39 volumio volumio[13834]: info: Loading plugin "outputs"... Jan 13 19:23:39 volumio volumio[13834]: info: Loading plugin "albumart"... Jan 13 19:23:39 volumio volumio[13834]: info: Plugin example_plugin is not enabled Jan 13 19:23:39 volumio volumio[13834]: info: Loading plugin "inputs"... Jan 13 19:23:39 volumio volumio[13834]: info: Loading plugin "updater_comm"... Jan 13 19:23:40 volumio volumio[13834]: info: Plugin mpdemulation is not enabled Jan 13 19:23:40 volumio volumio[13834]: info: Loading plugin "rest_api"... Jan 13 19:23:40 volumio volumio[13834]: info: Loading plugin "websocket"... Jan 13 19:23:40 volumio volumio[13834]: info: Starting Socket.io Server version 1.7.4 Jan 13 19:23:40 volumio volumio[13834]: info: Plugin fusiondsp is not enabled Jan 13 19:23:40 volumio volumio[13834]: info: Plugin mpdoutput is not enabled Jan 13 19:23:40 volumio volumio[13834]: info: Plugin RoonBridge is not enabled Jan 13 19:23:40 volumio volumio[13834]: info: Loading plugin "podcast"... Jan 13 19:23:40 volumio volumio[13834]: info: ControllerPodcast::constructor Jan 13 19:23:40 volumio go-librespot[14043]: time="2026-01-13T19:23:40-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 13 19:23:40 volumio go-librespot[14043]: time="2026-01-13T19:23:40-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 13 19:23:40 volumio go-librespot[14043]: time="2026-01-13T19:23:40-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 13 19:23:40 volumio go-librespot[14043]: time="2026-01-13T19:23:40-06:00" level=info msg="zeroconf server listening on port 37281" Jan 13 19:23:40 volumio volumio[13834]: info: Loading plugin "volusonic"... Jan 13 19:23:40 volumio go-librespot[14043]: time="2026-01-13T19:23:40-06:00" level=debug msg="obtained new client token: AAAAPKAQOGPOd26hN4Yh9jHq70ISGaEAeS6D011izjwJgEU544H8pgE9ytMQ+M8/6nGAhAFkRL5ZWw+MuHlM0bGzFes2yXkTJeH5wV2u+Oj14dJMMaYA5KPcczFJRBl4D69EvYqIRkvmzFz1slMkOSPSniAxJb7QIuIkKjNi3wwy9AHHs9jIM7wlRGEKuwJpiG/tnV6xDiLjMe8bwdc1f6H3szFI9esrcqOmgehWTdyipcinQz55xvFcHg==" Jan 13 19:23:40 volumio volumio[14049]: Forking 3 albumart workers Jan 13 19:23:40 volumio go-librespot[14043]: time="2026-01-13T19:23:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:40 volumio go-librespot[14043]: time="2026-01-13T19:23:40-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:40 volumio go-librespot[14043]: time="2026-01-13T19:23:40-06:00" level=debug msg="completed challenge" Jan 13 19:23:40 volumio go-librespot[14043]: time="2026-01-13T19:23: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 13 19:23:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:41 volumio volumio-remote-updater[14193]: [2026-01-13 19:23:41] [connect] Successful connection Jan 13 19:23:41 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 19:23:43 volumio volumio[13834]: info: Applying required configuration parameters for plugin volusonic Jan 13 19:23:43 volumio volumio[13834]: info: Loading plugin "backup_restore"... Jan 13 19:23:43 volumio volumio[14062]: Starting albumart workers Jan 13 19:23:43 volumio volumio[14063]: Starting albumart workers Jan 13 19:23:43 volumio volumio[14061]: Starting albumart workers Jan 13 19:23:43 volumio volumio[13834]: info: Applying required configuration parameters for plugin backup_restore Jan 13 19:23:43 volumio volumio[13834]: info: Plugin rpi_eeprom_config is not enabled Jan 13 19:23:43 volumio volumio[13834]: info: Plugin rpi_eeprom_updater is not enabled Jan 13 19:23:43 volumio volumio[13834]: info: Loading plugin "scheduledrestart"... Jan 13 19:23:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 13 19:23:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:43 volumio go-librespot[14094]: go-librespot daemon starting... Jan 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-06:00" level=debug msg="app state loaded" Jan 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:44 volumio volumio[13834]: info: Applying required configuration parameters for plugin scheduledrestart Jan 13 19:23:44 volumio volumio[13834]: info: Plugin Bluetoothremote is not enabled Jan 13 19:23:44 volumio volumio[13834]: info: Plugin music_services_shield is not enabled Jan 13 19:23:44 volumio volumio[13834]: info: Loading plugin "Systeminfo"... Jan 13 19:23:44 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.95.200 Jan 13 19:23:44 volumio avahi-daemon[664]: Registering new address record for 169.254.95.200 on eth0.IPv4. Jan 13 19:23:44 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:23:44 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:44 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:44 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-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 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-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 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-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 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-06:00" level=info msg="zeroconf server listening on port 33643" Jan 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-06:00" level=debug msg="obtained new client token: AACDacXxB+7oFBorFv9CxScnRZSODEEHVqJFxA1vjaPhswi4aGAvXuEBF0rTQe+tOxqTrujjaQzX00VG23EaI3fGP76SDZ3lRw3A40xgBCP7WradBqTohOqJjaYVegzjgUCTQHHzHswFIEVU38Jipc5Islli1GT6zMIVAH93nsQ9eWfYUwEFXqPKdSGO1H50cTxFt0R9yFuL71bZPUfrEwqZBRKNOzAkKHUI7Bm+4ooqcx+jynBykIF+KA==" Jan 13 19:23:44 volumio volumio[13834]: info: Plugin peppymeterbasic is not enabled Jan 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:44 volumio volumio[13834]: info: Loading plugin "peppyspectrum"... Jan 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23:44-06:00" level=debug msg="completed challenge" Jan 13 19:23:44 volumio go-librespot[14095]: time="2026-01-13T19:23: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 13 19:23:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:44 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.95.200 Jan 13 19:23:45 volumio volumio[13834]: info: Loading i18n strings for locale en Jan 13 19:23:45 volumio volumio[13834]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 19:23:45 volumio volumio[13834]: Updating browse sources language Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::initPlayerControls Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: Express server listening on port 3000 Jan 13 19:23:45 volumio volumio[13834]: [Metrics] WebUI: 19s 277.34ms Jan 13 19:23:45 volumio volumio[13834]: info: CoreStateMachine::resetVolumioState Jan 13 19:23:45 volumio volumio[13834]: info: CoreStateMachine::getcurrentVolume Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:45 volumio sudo[14142]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 19:23:45 volumio sudo[14142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:45 volumio sudo[14142]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:45 volumio sudo[14144]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 19:23:45 volumio sudo[14144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:45 volumio sudo[14144]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:45 volumio volumio[13834]: info: Volumio Network Manager: Network status updated: 1 Jan 13 19:23:45 volumio ntpd[872]: IO: Listen normally on 14824 eth0 169.254.95.200:123 Jan 13 19:23:45 volumio ntpd[872]: IO: new interface(s) found: waking up resolver Jan 13 19:23:45 volumio volumio[13834]: info: VolumeController:: Volume=100 Mute =false Jan 13 19:23:45 volumio volumio[13834]: info: CoreStateMachine::pushState Jan 13 19:23:45 volumio volumio[13834]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioPushState Jan 13 19:23:45 volumio volumio[13834]: info: CoreStateMachine::updateTrackBlock Jan 13 19:23:45 volumio volumio[13834]: info: CorePlayQueue::getTrackBlock Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 19:23:45 volumio volumio-remote-updater[14193]: [2026-01-13 19:23:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768353821 101 Jan 13 19:23:45 volumio volumio[13834]: 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 13 19:23:45 volumio volumio[13834]: info: Reloading queue from file Jan 13 19:23:45 volumio volumio[13834]: info: CoreStateMachine::setRepeat null single undefined Jan 13 19:23:45 volumio volumio[13834]: info: CoreStateMachine::pushState Jan 13 19:23:45 volumio volumio[13834]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioPushState Jan 13 19:23:45 volumio volumio[13834]: info: CoreStateMachine::setRandom null Jan 13 19:23:45 volumio volumio[13834]: info: CoreStateMachine::pushState Jan 13 19:23:45 volumio volumio[13834]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioPushState Jan 13 19:23:45 volumio volumio[13834]: info: Setting Device type: Raspberry PI Jan 13 19:23:45 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.95.200 Jan 13 19:23:45 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.95.200 Jan 13 19:23:45 volumio volumio[13834]: info: VolumeController:: Volume=100 Mute =false Jan 13 19:23:45 volumio volumio[13834]: info: CoreStateMachine::pushState Jan 13 19:23:45 volumio volumio[13834]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioPushState Jan 13 19:23:45 volumio avahi-daemon[664]: Withdrawing address record for 169.254.95.200 on eth0. Jan 13 19:23:45 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:23:45 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:23:45 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:45 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:45 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:45 volumio sudo[14167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 13 19:23:45 volumio sudo[14167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:45 volumio volumio[13834]: info: Completed loading Core Plugins Jan 13 19:23:45 volumio volumio[13834]: info: Preparing to generate the ALSA configuration file Jan 13 19:23:45 volumio sudo[14167]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:45 volumio volumio[13834]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 19:23:45 volumio volumio[13834]: info: Discovery: Found device Volumio Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioGetState Jan 13 19:23:45 volumio volumio[13834]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:45 volumio volumio[13834]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 19:23:45 volumio volumio[13834]: info: Discovery: Found device Volumio Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioGetState Jan 13 19:23:45 volumio volumio[13834]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:45 volumio volumio[13834]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 19:23:45 volumio volumio[13834]: info: Reading ALSA contributions from plugins. Jan 13 19:23:45 volumio volumio[13834]: info: Upmpdcli Daemon Started Jan 13 19:23:45 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 19:23:45 volumio volumio[13834]: info: Asound.conf file unchanged, so no further update is needed Jan 13 19:23:45 volumio volumio[13834]: info: Output device has changed, restarting MPD Jan 13 19:23:45 volumio volumio[13834]: info: Output device has changed, restarting Shairport Sync Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:45 volumio sudo[14178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 19:23:45 volumio sudo[14178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:45 volumio sudo[14178]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:45 volumio sudo[14180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 19:23:45 volumio sudo[14180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:45 volumio volumio[13834]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:23:45 volumio volumio[13834]: info: ___________ START PLUGINS ___________ Jan 13 19:23:45 volumio volumio[13834]: info: ControllerMpd::onStart: Initializing MPD Jan 13 19:23:45 volumio volumio[13834]: info: Creating MPD Configuration file Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:45 volumio volumio[13834]: info: [1768353825858] CoreMusicLibrary::Adding element Media Servers Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:45 volumio sudo[14188]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 19:23:45 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 13 19:23:45 volumio sudo[14188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:45 volumio sudo[14188]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:45 volumio sudo[14190]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 19:23:45 volumio sudo[14190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:45 volumio volumio[13834]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:45 volumio volumio[13834]: info: [1768353825971] CoreMusicLibrary::Adding element Last_100 Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:45 volumio volumio[13834]: info: [1768353825976] CoreMusicLibrary::Adding element Webradio Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:45 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 19:23:45 volumio volumio[13834]: info: Initializing BBC Radios Jan 13 19:23:45 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 19:23:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 19:23:45 volumio systemd[1]: mpd.service: Consumed 3.840s CPU time. Jan 13 19:23:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 19:23:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 19:23:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:46 volumio volumio[13834]: info: [1768353826048] CoreMusicLibrary::Adding element Bandcamp Discover Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:46 volumio volumio[13834]: info: [1768353826059] CoreMusicLibrary::Adding element SoundCloud Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source SoundCloud Jan 13 19:23:46 volumio volumio[13834]: info: Creating Spotify config file Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 19:23:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 19:23:46 volumio sudo[14219]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 19:23:46 volumio sudo[14219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 19:23:46 volumio sudo[14219]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:46 volumio volumio[13834]: info: [squeezelite_mc] Starting proxy server... Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:46 volumio volumio[13834]: info: [1768353826428] CoreMusicLibrary::Adding element YouTube2 Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source SoundCloud Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube2 Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:46 volumio volumio[13834]: info: [1768353826447] CoreMusicLibrary::Adding element YouTube Music Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source SoundCloud Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube2 Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube Music Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:46 volumio volumio[13834]: info: [1768353826459] CoreMusicLibrary::Adding element Podcast Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source SoundCloud Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube2 Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube Music Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Podcast Jan 13 19:23:46 volumio volumio[13834]: info: Loading i18n strings for locale en Jan 13 19:23:46 volumio volumio[13834]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 19:23:46 volumio volumio[13834]: Updating browse sources language Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source SoundCloud Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube2 Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube Music Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Podcast Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source SoundCloud Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube2 Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube Music Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Podcast Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:46 volumio volumio[13834]: info: [1768353826508] CoreMusicLibrary::Adding element Volusonic Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source SoundCloud Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube2 Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source YouTube Music Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Podcast Jan 13 19:23:46 volumio volumio[13834]: Cannot find translation for source Volusonic Jan 13 19:23:46 volumio volumio[13834]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 13 19:23:46 volumio volumio[13834]: info: Volumio Calling Home Jan 13 19:23:46 volumio volumio[13834]: info: [squeezelite_mc] Proxy server started on port 33519 Jan 13 19:23:46 volumio volumio[13834]: info: Preparing to generate the ALSA configuration file Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 19:23:46 volumio volumio[13834]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 19:23:46 volumio volumio[13834]: info: Reading ALSA contributions from plugins. Jan 13 19:23:46 volumio volumio[13834]: info: MPD Permissions set Jan 13 19:23:46 volumio volumio[13834]: info: MPD Permissions set Jan 13 19:23:46 volumio volumio[13834]: info: Spotify config file written Jan 13 19:23:46 volumio sudo[14229]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 13 19:23:46 volumio sudo[14229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:46 volumio volumio[13834]: 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 13 19:23:46 volumio volumio[13834]: info: VolumeController:: Volume=100 Mute =false Jan 13 19:23:46 volumio volumio[13834]: info: CoreStateMachine::pushState Jan 13 19:23:46 volumio volumio[13834]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::volumioPushState Jan 13 19:23:46 volumio volumio[13834]: info: [squeezelite_mc] Server discovery started Jan 13 19:23:46 volumio volumio[13834]: info: [squeezelite_mc] Player finder started Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 13 19:23:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:46 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:47 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:47 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:47 volumio volumio[13834]: info: No need to fix Spotify hosts Jan 13 19:23:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:47 volumio go-librespot[14233]: go-librespot daemon starting... Jan 13 19:23:47 volumio sudo[14229]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-06:00" level=debug msg="app state loaded" Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:47 volumio volumio[13834]: 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 13 19:23:47 volumio volumio[13834]: info: Volumio called home Jan 13 19:23:47 volumio volumio[13834]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 13 19:23:47 volumio volumio[13834]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 13 19:23:47 volumio volumio[13834]: 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 13 19:23:47 volumio volumio[13834]: info: Starting Shairport Sync Jan 13 19:23:47 volumio ntpd[872]: IO: Deleting interface #14824 eth0, 169.254.95.200#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Jan 13 19:23:47 volumio volumio[13834]: info: Starting Shairport Sync Jan 13 19:23:47 volumio volumio[13834]: info: Starting Shairport Sync Jan 13 19:23:47 volumio sudo[14256]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:23:47 volumio sudo[14256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:23:47 volumio sudo[14258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-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 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-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 13 19:23:47 volumio sudo[14258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:47 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-06:00" level=info msg="zeroconf server listening on port 42331" Jan 13 19:23:47 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 19:23:47 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:47 volumio systemd[1]: shairport-sync.service: Consumed 1.964s CPU time. Jan 13 19:23:47 volumio sudo[14261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:23:47 volumio sudo[14261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:47 volumio sudo[14254]: 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 13 19:23:47 volumio sudo[14254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:47 volumio sudo[14254]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:47 volumio volumio[13834]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 19:23:47 volumio volumio[13834]: SPOTIFY: BQC7X3R-BWMDIHW0KZSfV7dMwy041ltfYhQY4l7ZJMzu8XB1pdXGv0FqBN1YDlAj1IS9bqqUvk2Zk2R9DFY77XxMfFOL-nEsZ5Jqp09yLuPhSnWM1w-XB-p-sRU4KBW0dEBowawHfCbJ5nsgZn6q-KXMHPIEsjLSSWVlxw_bzfNyIOVXHQag3DfHo2ZsuAdXy2iCU2kTEnbDrMKHdd_xZHnXnHBtcC1ojw__pCg Jan 13 19:23:47 volumio volumio[13834]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 19:23:47 volumio volumio[13834]: info: New Spotify access token = BQC7X3R-BWMDIHW0KZSfV7dMwy041ltfYhQY4l7ZJMzu8XB1pdXGv0FqBN1YDlAj1IS9bqqUvk2Zk2R9DFY77XxMfFOL-nEsZ5Jqp09yLuPhSnWM1w-XB-p-sRU4KBW0dEBowawHfCbJ5nsgZn6q-KXMHPIEsjLSSWVlxw_bzfNyIOVXHQag3DfHo2ZsuAdXy2iCU2kTEnbDrMKHdd_xZHnXnHBtcC1ojw__pCg Jan 13 19:23:47 volumio volumio[13834]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 13 19:23:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:47 volumio sudo[14256]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:47 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-06:00" level=debug msg="obtained new client token: AACZpz6LmBvComKPlwav9BJlFfIpavAFCMRfRcT0VDK4msXKk0XK8TdYoPIGQNQX/ZdBsMcb5gNSShJjMSPb+sL0vbUFgp/iAXVHABEtH1xLSvkaRSACo+5/oGoCjy4XmhB1Z8G2PBEZQ1LER8QZ2Gi+ttj7O4ChHf/8W5qs8MkF8sX5GEwHtThOC19YKuXsAB+Q7ZWaMWuPC7ZBHabJmRTKuH6HKrCvbFT0sxlUgTjFlDDHdcUaawOtQQ==" Jan 13 19:23:47 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 19:23:47 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:47 volumio volumio[13834]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 13 19:23:47 volumio sudo[14258]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:47 volumio volumio[13834]: info: Asound.conf file unchanged, so no further update is needed Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:47 volumio sudo[14261]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:47 volumio volumio[13834]: info: Output device has changed, restarting MPD Jan 13 19:23:47 volumio volumio[13834]: info: Output device has changed, restarting Shairport Sync Jan 13 19:23:47 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:47 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:47 volumio sudo[14270]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 13 19:23:47 volumio sudo[14270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:47 volumio sudo[14270]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23:47-06:00" level=debug msg="completed challenge" Jan 13 19:23:47 volumio sudo[14274]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 19:23:47 volumio sudo[14274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:47 volumio go-librespot[14244]: time="2026-01-13T19:23: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 13 19:23:47 volumio volumio[13834]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:23:47 volumio sudo[14272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 19:23:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:47 volumio sudo[14272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:47 volumio sudo[14272]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:47 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 19:23:47 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 19:23:47 volumio systemd[1]: mpd.service: Consumed 1.640s CPU time. Jan 13 19:23:47 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 19:23:47 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 19:23:47 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 19:23:47 volumio volumio[13834]: info: Shairport-Sync Started Jan 13 19:23:47 volumio volumio[13834]: Error adding Membership: Error: addMembership EINVAL Jan 13 19:23:47 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 19:23:47 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 19:23:47 volumio volumio[13834]: info: MPD Permissions set Jan 13 19:23:47 volumio volumio[13834]: 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 13 19:23:48 volumio volumio[13834]: info: Shairport-Sync Started Jan 13 19:23:48 volumio volumio[13834]: info: Shairport-Sync Started Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:48 volumio sudo[14303]: 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 13 19:23:48 volumio sudo[14303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:48 volumio sudo[14303]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::volumioGetState Jan 13 19:23:48 volumio volumio[13834]: info: CorePlayQueue::getTrack 0 Jan 13 19:23:48 volumio volumio[13834]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 13 19:23:48 volumio volumio[13834]: info: Starting Shairport Sync Jan 13 19:23:48 volumio sudo[14300]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 19:23:48 volumio sudo[14300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 19:23:48 volumio sudo[14300]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:48 volumio sudo[14311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 13 19:23:48 volumio sudo[14311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:48 volumio sudo[14314]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:23:48 volumio sudo[14314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:48 volumio volumio[13834]: 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 13 19:23:48 volumio volumio[13834]: info: Spotify Successfully logged in Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:23:48 volumio volumio[13834]: info: [1768353828565] CoreMusicLibrary::Adding element Spotify Jan 13 19:23:48 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:23:48 volumio volumio[13834]: Cannot find translation for source Bandcamp Discover Jan 13 19:23:48 volumio volumio[13834]: Cannot find translation for source SoundCloud Jan 13 19:23:48 volumio volumio[13834]: Cannot find translation for source YouTube2 Jan 13 19:23:48 volumio volumio[13834]: Cannot find translation for source YouTube Music Jan 13 19:23:48 volumio volumio[13834]: Cannot find translation for source Podcast Jan 13 19:23:48 volumio volumio[13834]: Cannot find translation for source Volusonic Jan 13 19:23:48 volumio volumio[13834]: Cannot find translation for source Spotify Jan 13 19:23:48 volumio systemd[1]: Reloading. Jan 13 19:23:49 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:49 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:49 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:23:49 volumio volumio[13834]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:23:49 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 19:23:50 volumio volumio[13834]: info: go-librespot daemon successfully initialized Jan 13 19:23:50 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.55.37 Jan 13 19:23:50 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:23:50 volumio avahi-daemon[664]: Registering new address record for 169.254.55.37 on eth0.IPv4. Jan 13 19:23:50 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.55.37 Jan 13 19:23:51 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.55.37 Jan 13 19:23:51 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.55.37 Jan 13 19:23:51 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:23:51 volumio avahi-daemon[664]: Withdrawing address record for 169.254.55.37 on eth0. Jan 13 19:23:51 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:23:51 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 13 19:23:51 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 13 19:23:51 volumio sudo[14311]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:51 volumio volumio[13834]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jan 13 19:23:51 volumio sudo[14382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:51 volumio sudo[14382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:51 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:51 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:51 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:51 volumio go-librespot[14385]: go-librespot daemon starting... Jan 13 19:23:51 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 19:23:51 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 19:23:51 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:51 volumio systemd[1]: shairport-sync.service: Consumed 1.437s CPU time. Jan 13 19:23:51 volumio go-librespot[14386]: time="2026-01-13T19:23:51-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:51 volumio go-librespot[14386]: time="2026-01-13T19:23:51-06:00" level=debug msg="app state loaded" Jan 13 19:23:51 volumio go-librespot[14386]: time="2026-01-13T19:23:51-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:51 volumio go-librespot[14386]: time="2026-01-13T19:23:51-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:23:52 volumio sudo[14314]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:52 volumio volumio[13834]: info: Shairport-Sync Started Jan 13 19:23:52 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:52 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:52 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:52 volumio sudo[14382]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:52 volumio volumio[13834]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 13 19:23:52 volumio sudo[14394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 13 19:23:52 volumio sudo[14394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:52 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 13 19:23:52 volumio go-librespot[14386]: time="2026-01-13T19:23:52-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 13 19:23:52 volumio go-librespot[14386]: time="2026-01-13T19:23:52-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 13 19:23:52 volumio go-librespot[14386]: time="2026-01-13T19:23:52-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 13 19:23:52 volumio go-librespot[14386]: time="2026-01-13T19:23:52-06:00" level=info msg="zeroconf server listening on port 44895" Jan 13 19:23:52 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 13 19:23:52 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 13 19:23:52 volumio go-librespot[14386]: time="2026-01-13T19:23:52-06:00" level=debug msg="obtained new client token: AAAZl5XkVwh+sruNhL0F1j8s9mi8Fd0abS2Bk2aadFqNux5gNXwOEIPk5eMKb+OOBxAMP5A0ttmHPdPyuR7Jk6vn7VsD71bp1EsSd03BHp7yB7V0Ok5oFOWJv2MxXrZP+GRW3WU6EHu1+6uKftVySoHf5TofvVfwIhjQys3OTbTZPYWJK4w7BX9I3vkMoIL+lcT+Ds+bFB40CyvB9CYoG6tLdb3Brppkk3tjpr8ew9wdRxj4eoRws64cOg==" Jan 13 19:23:52 volumio sudo[14394]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:52 volumio go-librespot[14386]: time="2026-01-13T19:23:52-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:52 volumio go-librespot[14386]: time="2026-01-13T19:23:52-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:52 volumio go-librespot[14386]: time="2026-01-13T19:23:52-06:00" level=debug msg="completed challenge" Jan 13 19:23:52 volumio go-librespot[14386]: time="2026-01-13T19:23:52-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 19:23:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:53 volumio volumio[13834]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:53 volumio sudo[14413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:53 volumio sudo[14413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:53 volumio mpd[14316]: 2026-01-13T19:23:53 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 13 19:23:53 volumio sudo[14413]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:53 volumio volumio[13834]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 13 19:23:53 volumio sudo[14417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 13 19:23:53 volumio sudo[14417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:53 volumio sudo[14417]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:53 volumio volumio[13834]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 13 19:23:53 volumio sudo[14420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 13 19:23:53 volumio sudo[14420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:53 volumio volumio[13834]: info: Initializing connection to go-librespot Websocket Jan 13 19:23:53 volumio volumio[13834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 19:23:53 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 13 19:23:53 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 13 19:23:53 volumio sudo[14180]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:53 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 13 19:23:53 volumio sudo[14274]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:53 volumio sudo[14190]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:53 volumio sudo[14420]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:53 volumio volumio[13834]: error: MPD error: The expression evaluated to a falsy value: Jan 13 19:23:53 volumio volumio[13834]: assert.ok(self.idling) Jan 13 19:23:53 volumio volumio[13834]: error: The expression evaluated to a falsy value: Jan 13 19:23:53 volumio volumio[13834]: assert.ok(self.idling) Jan 13 19:23:53 volumio volumio[13834]: error: MPD error: The expression evaluated to a falsy value: Jan 13 19:23:53 volumio volumio[13834]: assert.ok(self.idling) Jan 13 19:23:53 volumio volumio[13834]: error: The expression evaluated to a falsy value: Jan 13 19:23:53 volumio volumio[13834]: assert.ok(self.idling) Jan 13 19:23:53 volumio volumio[13834]: info: MPD running with PID14316 Jan 13 19:23:53 volumio volumio[13834]: ,establishing connection Jan 13 19:23:53 volumio volumio[13834]: error: updateQueue error: null Jan 13 19:23:53 volumio volumio[13834]: error: updateQueue error: null Jan 13 19:23:53 volumio volumio[13834]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:54 volumio sudo[14431]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:54 volumio sudo[14431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:54 volumio sudo[14431]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:54 volumio volumio[13834]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:54 volumio sudo[14434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:54 volumio sudo[14434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:54 volumio sudo[14434]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:55 volumio volumio[13834]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:55 volumio sudo[14437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:55 volumio sudo[14437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:55 volumio sudo[14437]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:55 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.163.89 Jan 13 19:23:55 volumio avahi-daemon[664]: Registering new address record for 169.254.163.89 on eth0.IPv4. Jan 13 19:23:55 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:23:55 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.163.89 Jan 13 19:23:55 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:55 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:55 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 13 19:23:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:55 volumio volumio[13834]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:56 volumio sudo[14457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:56 volumio sudo[14457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:23:56 volumio go-librespot[14455]: go-librespot daemon starting... Jan 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-06:00" level=debug msg="app state loaded" Jan 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-06:00" level=debug msg="stored credentials not found" Jan 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:23:56 volumio sudo[14457]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:56 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.163.89 Jan 13 19:23:56 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.163.89 Jan 13 19:23:56 volumio avahi-daemon[664]: Withdrawing address record for 169.254.163.89 on eth0. Jan 13 19:23:56 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:23:56 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:23:56 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:56 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:23:56 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:23:56 volumio volumio[13834]: info: Initializing connection to go-librespot Websocket Jan 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-06:00" level=debug msg="new websocket client" Jan 13 19:23:56 volumio volumio[13834]: info: Connection to go-librespot Websocket established Jan 13 19:23:56 volumio sudo[14484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 19:23:56 volumio sudo[14484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:56 volumio sudo[14486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 19:23:56 volumio sudo[14486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-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 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-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 13 19:23:56 volumio sudo[14488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 19:23:56 volumio sudo[14488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-06:00" level=info msg="zeroconf server listening on port 45819" Jan 13 19:23:56 volumio volumio[13834]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 19:23:56 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 13 19:23:56 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 13 19:23:56 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 13 19:23:56 volumio sudo[14493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 19:23:56 volumio sudo[14493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-06:00" level=debug msg="obtained new client token: AACynwfXe/Rcb3u5KEr+oQGQILUD7UmpS+2TrLp0/lVWPCixg32mDAeAGfFqStgfSqe1xrFikRk9aG4sHz8oIAfoRupgEMIbFfewULF9GwE7neSjM5EV9dv+NVj683pyzLoWDHVNeUAaGiQv1qYaBvuS0L0yVWZAFwQ5fBgwUxOyMyJnJTCn59ynfmq+65P8o9r/kXQckYloqoy/xd+ywBwCYl/Vvu2Z9pYW0vhZPPsf/62JcKgKXORrHQ==" Jan 13 19:23:56 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 13 19:23:56 volumio sudo[14488]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:56 volumio sudo[14486]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:56 volumio sudo[14484]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:56 volumio mpd_monitor.sh[14494]: MPD Monitor Service: Starting MPD Monitor Service Jan 13 19:23:56 volumio volumio[13834]: info: Successfully started MPD Monitor Jan 13 19:23:56 volumio volumio[13834]: info: Successfully started MPD Monitor Jan 13 19:23:56 volumio volumio[13834]: info: Successfully started MPD Monitor Jan 13 19:23:56 volumio go-librespot[14459]: time="2026-01-13T19:23:56-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:23:56 volumio sudo[14493]: pam_unix(sudo:session): session closed for user root Jan 13 19:23:56 volumio volumio[13834]: info: Completed starting Core Plugins Jan 13 19:23:56 volumio volumio[13834]: info: ------------------------------------------- Jan 13 19:23:56 volumio volumio[13834]: info: ----- MyVolumio plugins startup ---- Jan 13 19:23:56 volumio volumio[13834]: info: ------------------------------------------- Jan 13 19:23:56 volumio volumio[13834]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 13 19:23:57 volumio go-librespot[14459]: time="2026-01-13T19:23:57-06:00" level=debug msg="completed keyexchange" Jan 13 19:23:57 volumio go-librespot[14459]: time="2026-01-13T19:23:57-06:00" level=debug msg="completed challenge" Jan 13 19:23:57 volumio go-librespot[14459]: time="2026-01-13T19:23:57-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 13 19:23:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:23:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:23:57 volumio volumio[13834]: info: Connection to go-librespot Websocket closed Jan 13 19:23:59 volumio volumio[13834]: info: Getting Spotify volume Jan 13 19:23:59 volumio volumio[13834]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 19:23:59 volumio volumio[13834]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 19:23:59 volumio volumio[13834]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 13 19:23:59 volumio volumio[13834]: errno: -111, Jan 13 19:23:59 volumio volumio[13834]: code: 'ECONNREFUSED', Jan 13 19:23:59 volumio volumio[13834]: syscall: 'connect', Jan 13 19:23:59 volumio volumio[13834]: address: '127.0.0.1', Jan 13 19:23:59 volumio volumio[13834]: port: 9879, Jan 13 19:23:59 volumio volumio[13834]: response: undefined Jan 13 19:23:59 volumio volumio[13834]: } Jan 13 19:23:59 volumio volumio[13834]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 19:24:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 13 19:24:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:00 volumio go-librespot[14525]: go-librespot daemon starting... Jan 13 19:24:00 volumio go-librespot[14526]: time="2026-01-13T19:24:00-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:24:00 volumio go-librespot[14526]: time="2026-01-13T19:24:00-06:00" level=debug msg="app state loaded" Jan 13 19:24:00 volumio go-librespot[14526]: time="2026-01-13T19:24:00-06:00" level=debug msg="stored credentials not found" Jan 13 19:24:00 volumio go-librespot[14526]: time="2026-01-13T19:24:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:24:00 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.203.96 Jan 13 19:24:00 volumio avahi-daemon[664]: Registering new address record for 169.254.203.96 on eth0.IPv4. Jan 13 19:24:00 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:24:00 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:00 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:00 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:00 volumio sudo[14550]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-13 19:23' Jan 13 19:24:00 volumio sudo[14550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:01 volumio go-librespot[14526]: time="2026-01-13T19:24: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 13 19:24:01 volumio go-librespot[14526]: time="2026-01-13T19:24: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 13 19:24:01 volumio go-librespot[14526]: time="2026-01-13T19:24: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 13 19:24:01 volumio go-librespot[14526]: time="2026-01-13T19:24:01-06:00" level=info msg="zeroconf server listening on port 45237" Jan 13 19:24:01 volumio sudo[14550]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:01 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.203.96 Jan 13 19:24:01 volumio volumio-remote-updater[14193]: [2026-01-13 19:24:01] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 13 19:24:01 volumio volumio-remote-updater[14193]: [2026-01-13 19:24:01] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 13 19:24:01 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:24:01 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 13 19:24:01 volumio systemd[1]: volumio.service: Consumed 47.626s CPU time. Jan 13 19:24:01 volumio go-librespot[14526]: time="2026-01-13T19:24:01-06:00" level=debug msg="obtained new client token: AAD0TVhy/5vhRh50QjcQpN6F1l3K9+ttpKU1kBPC7FMtURbVU09NY3My0tvZBCefR43qdqxR5OJmosTIOnh4psY8nUxjdZaUojBYKCYYk3BTvhvO7slYYB4MSXbvPFFxDg29fK8ylR18Whq6YvJzCGqVepn/c1v3CAPtMexUyB52c1HxzJzegfNaxi45kSoNpvdmfGF16uVc6H/CHoTCKs4hp6qR5/GuvtuiyP+sYC60qGfbqIBdLkrX2g==" Jan 13 19:24:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 13 19:24:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 13 19:24:01 volumio go-librespot[14526]: time="2026-01-13T19:24:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:24:01 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 23519. Jan 13 19:24:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 13 19:24:01 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 13 19:24:01 volumio systemd[1]: volumio.service: Consumed 47.626s CPU time. Jan 13 19:24:01 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 13 19:24:01 volumio go-librespot[14526]: time="2026-01-13T19:24:01-06:00" level=debug msg="completed keyexchange" Jan 13 19:24:01 volumio go-librespot[14526]: time="2026-01-13T19:24:01-06:00" level=debug msg="completed challenge" Jan 13 19:24:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 13 19:24:01 volumio go-librespot[14526]: time="2026-01-13T19:24: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 13 19:24:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:24:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:24:02 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.203.96 Jan 13 19:24:02 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.203.96 Jan 13 19:24:02 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:24:02 volumio avahi-daemon[664]: Withdrawing address record for 169.254.203.96 on eth0. Jan 13 19:24:02 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:02 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:02 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:02 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:24:04 volumio volumio[14568]: info: ------------------------------------------- Jan 13 19:24:04 volumio volumio[14568]: info: ----- Volumio3 ---- Jan 13 19:24:04 volumio volumio[14568]: info: ------------------------------------------- Jan 13 19:24:04 volumio volumio[14568]: info: ----- System startup ---- Jan 13 19:24:04 volumio volumio[14568]: info: ------------------------------------------- Jan 13 19:24:04 volumio volumio[14568]: info: MYVOLUMIO Environment detected Jan 13 19:24:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jan 13 19:24:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:04 volumio volumio[14568]: info: Plugin folders cleanup Jan 13 19:24:04 volumio volumio[14568]: info: Scanning into folder /volumio/app/plugins/ Jan 13 19:24:04 volumio volumio[14568]: info: Scanning category audio_interface Jan 13 19:24:04 volumio volumio[14568]: info: Scanning category miscellanea Jan 13 19:24:05 volumio volumio[14568]: info: Scanning category music_service Jan 13 19:24:05 volumio volumio[14568]: info: Scanning category plugins.json Jan 13 19:24:05 volumio volumio[14568]: info: Scanning category system_controller Jan 13 19:24:05 volumio volumio[14568]: info: Scanning category user_interface Jan 13 19:24:05 volumio volumio[14568]: info: Scanning into folder /data/plugins/ Jan 13 19:24:05 volumio volumio[14568]: info: Scanning category audio_interface Jan 13 19:24:05 volumio volumio[14568]: info: Scanning category music_service Jan 13 19:24:05 volumio volumio[14568]: info: Scanning category system_controller Jan 13 19:24:05 volumio volumio[14568]: info: Scanning category system_hardware Jan 13 19:24:05 volumio volumio[14568]: info: Scanning category user_interface Jan 13 19:24:05 volumio volumio[14568]: info: Plugin folders cleanup completed Jan 13 19:24:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:05 volumio volumio[14568]: info: ------------------------------------------- Jan 13 19:24:05 volumio volumio[14568]: info: ----- Core plugins startup ---- Jan 13 19:24:05 volumio volumio[14568]: info: ------------------------------------------- Jan 13 19:24:05 volumio volumio[14568]: info: Loading plugins from folder /volumio/app/plugins/ Jan 13 19:24:05 volumio go-librespot[14608]: go-librespot daemon starting... Jan 13 19:24:05 volumio volumio[14568]: info: Adding plugin upnp to MyMusic Plugins Jan 13 19:24:05 volumio volumio[14568]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 13 19:24:05 volumio volumio[14568]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 13 19:24:05 volumio volumio[14568]: info: Loading plugins from folder /data/plugins/ Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-06:00" level=debug msg="app state loaded" Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-06:00" level=debug msg="stored credentials not found" Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:24:05 volumio volumio[14568]: info: Loading plugin "system"... Jan 13 19:24:05 volumio volumio[14568]: info: Loading plugin "appearance"... Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-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 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-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 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-06:00" level=info msg="zeroconf server listening on port 32941" Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-06:00" level=debug msg="obtained new client token: AABNwFNFc8K2JlgoFF2rb8tlZkmE8N2RJPOwGAIxGOdgTcLAWak/Y1iSQ/1eDbY3YpC9CF2X4fTmHgl57xe9sh17InuF32u/8RAU/CBM/KHVwEYnmQKyGHO7KyR7Ngg/LQ6WS8HftCoCJs1qkdrDfIuoFz3wNDx5bUsyTxENPXLJQ/E+Rxmkz4rftAPM6EDQv1cR7Cx8BIWrWvJgPILCDVu+munb/UrHl0YTKAjB32bAuov/ibRyXlzs1g==" Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-06:00" level=debug msg="completed keyexchange" Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24:05-06:00" level=debug msg="completed challenge" Jan 13 19:24:05 volumio go-librespot[14609]: time="2026-01-13T19:24: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 13 19:24:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:24:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:24:06 volumio volumio[14568]: info: Loading plugin "network"... Jan 13 19:24:06 volumio volumio[14568]: info: Refreshing Cached IP Addresses Jan 13 19:24:06 volumio sudo[14620]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 19:24:06 volumio sudo[14620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:06 volumio sudo[14622]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 19:24:06 volumio sudo[14622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:06 volumio volumio[14568]: info: Loading plugin "services"... Jan 13 19:24:06 volumio sudo[14620]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:06 volumio volumio[14568]: info: Loading plugin "alsa_controller"... Jan 13 19:24:06 volumio sudo[14622]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:06 volumio sudo[14630]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 13 19:24:06 volumio sudo[14630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:06 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 19:24:06 volumio volumio[14568]: info: Loading plugin "wizard"... Jan 13 19:24:06 volumio volumio[14568]: info: Loading plugin "networkfs"... Jan 13 19:24:06 volumio volumio[14568]: info: Starting Udev Watcher for removable devices Jan 13 19:24:06 volumio volumio[14568]: info: Ignoring mount for partition: boot Jan 13 19:24:06 volumio volumio[14568]: info: Ignoring mount for partition: volumio Jan 13 19:24:06 volumio volumio[14568]: info: Ignoring mount for partition: volumio_data Jan 13 19:24:06 volumio volumio[14568]: info: Mounting Device Wikipedia Jan 13 19:24:06 volumio volumio-remote-updater[14193]: [2026-01-13 19:24:06] [connect] Successful connection Jan 13 19:24:06 volumio sudo[14659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 13 19:24:06 volumio sudo[14659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:06 volumio sudo[14659]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:06 volumio volumio[14568]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 13 19:24:06 volumio volumio[14568]: dmesg(1) may have more information after failed mount system call. Jan 13 19:24:06 volumio volumio[14568]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 13 19:24:06 volumio volumio[14568]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 13 19:24:06 volumio volumio[14568]: dmesg(1) may have more information after failed mount system call. Jan 13 19:24:06 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 19:24:06 volumio volumio[14568]: info: Loading plugin "volumio_command_line_client"... Jan 13 19:24:06 volumio volumio[14568]: info: Loading plugin "upnp"... Jan 13 19:24:06 volumio volumio[14568]: info: [1768353846616] Starting Upmpd Daemon Jan 13 19:24:06 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 19:24:06 volumio volumio[14568]: info: Loading plugin "my_music"... Jan 13 19:24:06 volumio volumio[14568]: info: Loading plugin "mpd"... Jan 13 19:24:06 volumio sudo[14630]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:06 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.2.224 Jan 13 19:24:06 volumio avahi-daemon[664]: Registering new address record for 169.254.2.224 on eth0.IPv4. Jan 13 19:24:06 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:24:07 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:07 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:07 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:07 volumio volumio[14568]: info: Loading plugin "upnp_browser"... Jan 13 19:24:07 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.2.224 Jan 13 19:24:07 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.2.224 Jan 13 19:24:07 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.2.224 Jan 13 19:24:08 volumio avahi-daemon[664]: Withdrawing address record for 169.254.2.224 on eth0. Jan 13 19:24:08 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:24:08 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:08 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:08 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:08 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:24:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Jan 13 19:24:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:08 volumio go-librespot[14693]: go-librespot daemon starting... Jan 13 19:24:08 volumio go-librespot[14694]: time="2026-01-13T19:24:08-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:24:08 volumio go-librespot[14694]: time="2026-01-13T19:24:08-06:00" level=debug msg="app state loaded" Jan 13 19:24:08 volumio go-librespot[14694]: time="2026-01-13T19:24:08-06:00" level=debug msg="stored credentials not found" Jan 13 19:24:08 volumio go-librespot[14694]: time="2026-01-13T19:24:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:24:09 volumio go-librespot[14694]: time="2026-01-13T19:24: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-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:24:09 volumio go-librespot[14694]: time="2026-01-13T19:24:09-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 13 19:24:09 volumio go-librespot[14694]: time="2026-01-13T19:24:09-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 13 19:24:09 volumio go-librespot[14694]: time="2026-01-13T19:24:09-06:00" level=info msg="zeroconf server listening on port 46717" Jan 13 19:24:09 volumio go-librespot[14694]: time="2026-01-13T19:24:09-06:00" level=debug msg="obtained new client token: AADTY8/+8pU2A/OfAhapUGKZT/Bfw78T8sefb0f3yS1KvdsINPOV2SrzzqSlNkH1A/z9He5EjbsFQ9Y24IQhPaUkFs7DRoR/tYIGQtls04Tvifsa/7IIL2fBlJIlppIo3purSG6CjlMpzkla4ckTp0eqVyyQ2wNmDzaSsYF4xeHYHpcQ2qoteTwavG5wnNrH/OkkGwVJdEehXCB++IlQ98aIFACF7mfJTx+UE9APtAJ6Trk3w8XKgqpFWg==" Jan 13 19:24:09 volumio go-librespot[14694]: time="2026-01-13T19:24:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:24:09 volumio go-librespot[14694]: time="2026-01-13T19:24:09-06:00" level=debug msg="completed keyexchange" Jan 13 19:24:09 volumio go-librespot[14694]: time="2026-01-13T19:24:09-06:00" level=debug msg="completed challenge" Jan 13 19:24:09 volumio go-librespot[14694]: time="2026-01-13T19:24: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 13 19:24:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:24:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:24:09 volumio volumio[14568]: info: Loading plugin "alarm-clock"... Jan 13 19:24:10 volumio volumio[14568]: info: Loading plugin "airplay_emulation"... Jan 13 19:24:10 volumio volumio[14568]: info: Starting Shairport Sync Jan 13 19:24:10 volumio volumio[14568]: info: Loading plugin "last_100"... Jan 13 19:24:10 volumio volumio[14568]: info: Loading plugin "webradio"... Jan 13 19:24:10 volumio volumio[14568]: info: Loading plugin "i2s_dacs"... Jan 13 19:24:10 volumio volumio[14568]: info: I2S DAC not set, start Auto-detection Jan 13 19:24:10 volumio volumio[14568]: info: Loading plugin "volumiodiscovery"... Jan 13 19:24:10 volumio volumio[14568]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 13 19:24:10 volumio volumio[14568]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 19:24:10 volumio volumio[14568]: *** WARNING *** For more information see Jan 13 19:24:10 volumio volumio[14568]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 13 19:24:10 volumio volumio[14568]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 19:24:10 volumio volumio[14568]: *** WARNING *** For more information see Jan 13 19:24:10 volumio node[14568]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 13 19:24:10 volumio node[14568]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 19:24:10 volumio node[14568]: *** WARNING *** For more information see Jan 13 19:24:10 volumio node[14568]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 13 19:24:10 volumio node[14568]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 19:24:10 volumio node[14568]: *** WARNING *** For more information see Jan 13 19:24:10 volumio volumio[14568]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 13 19:24:10 volumio volumio[14568]: info: Discovery: Started advertising with name: Volumio Jan 13 19:24:10 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 19:24:10 volumio volumio[14568]: info: Loading plugin "bandcamp"... Jan 13 19:24:11 volumio volumio[14568]: info: Plugin calmradio is not enabled Jan 13 19:24:11 volumio volumio[14568]: info: Loading plugin "soundcloud"... Jan 13 19:24:12 volumio volumio[14568]: info: Loading plugin "spop"... Jan 13 19:24:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Jan 13 19:24:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:12 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.79.158 Jan 13 19:24:12 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:24:12 volumio avahi-daemon[664]: Registering new address record for 169.254.79.158 on eth0.IPv4. Jan 13 19:24:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:12 volumio go-librespot[14703]: go-librespot daemon starting... Jan 13 19:24:12 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:12 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:12 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:12 volumio go-librespot[14717]: time="2026-01-13T19:24:12-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:24:12 volumio go-librespot[14717]: time="2026-01-13T19:24:12-06:00" level=debug msg="app state loaded" Jan 13 19:24:12 volumio go-librespot[14717]: time="2026-01-13T19:24:12-06:00" level=debug msg="stored credentials not found" Jan 13 19:24:12 volumio go-librespot[14717]: time="2026-01-13T19:24:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:24:13 volumio go-librespot[14717]: time="2026-01-13T19:24:13-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 13 19:24:13 volumio go-librespot[14717]: time="2026-01-13T19:24:13-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 13 19:24:13 volumio go-librespot[14717]: time="2026-01-13T19:24:13-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 13 19:24:13 volumio go-librespot[14717]: time="2026-01-13T19:24:13-06:00" level=info msg="zeroconf server listening on port 42823" Jan 13 19:24:13 volumio go-librespot[14717]: time="2026-01-13T19:24:13-06:00" level=debug msg="obtained new client token: AABRUMipPC6t2q9NJ2f9H+N9dGgnKHxkfiNxNxjAqHRHNWbii1sxK8G302RgT75PO5fzK+XJFl1d945UH1eCnhaVr9GXQemhEfen13gPZQ94HTGPZrLxdm4496LlY/Jsxf4FPjExVX7pINfbh8lPbKIziKIiVZCdJWAfjkJn7CDx28jf17DqyPUUF1zvjgRaSrQQQs+ZAStMB2Q5GwveyKFPV0/Tv9VudtY+W+G9zD+dWwSjC21+BwGOug==" Jan 13 19:24:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.79.158 Jan 13 19:24:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.79.158 Jan 13 19:24:13 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.79.158 Jan 13 19:24:13 volumio avahi-daemon[664]: Withdrawing address record for 169.254.79.158 on eth0. Jan 13 19:24:13 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:24:13 volumio go-librespot[14717]: time="2026-01-13T19:24:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:24:13 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:13 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:13 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:13 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:24:13 volumio go-librespot[14717]: time="2026-01-13T19:24:13-06:00" level=debug msg="completed keyexchange" Jan 13 19:24:13 volumio go-librespot[14717]: time="2026-01-13T19:24:13-06:00" level=debug msg="completed challenge" Jan 13 19:24:13 volumio go-librespot[14717]: time="2026-01-13T19:24: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 13 19:24:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:24:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:24:14 volumio volumio[14568]: info: Loading plugin "squeezelite_mc"... Jan 13 19:24:15 volumio volumio[14568]: info: Loading plugin "youtube2"... Jan 13 19:24:15 volumio volumio[14568]: info: Loading plugin "ytcr"... Jan 13 19:24:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Jan 13 19:24:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:16 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 19:24:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:16 volumio go-librespot[14762]: go-librespot daemon starting... Jan 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-06:00" level=debug msg="app state loaded" Jan 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-06:00" level=debug msg="stored credentials not found" Jan 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:24:17 volumio volumio[14568]: info: Loading plugin "ytmusic"... Jan 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-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 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-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 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-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 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-06:00" level=info msg="zeroconf server listening on port 36629" Jan 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-06:00" level=debug msg="obtained new client token: AAAfxYM5AtsEUNMEY9aOv+7+LHWXDFSxIn5lg3WLqMivbBOU5GTJYUfhKrfeZJyd46tezvR2tA3H06RbR9RYRWAS/4Q7VsYTfNbHBr5xT260WIQ3Rel7jAmXlznsWAmJ5D93yzDPLLoR3/eJK5Ra+3Uv+8htNcrM1qk6xOQRrbUBJeMQ2LWBYv8RJQ1xkScjRbgpRsDTUEnto07HHEGASwtEiNsV7mEp1/Hpv5KYPKMp4AyPih4Gk0Cpxw==" Jan 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-06:00" level=debug msg="completed keyexchange" Jan 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24:17-06:00" level=debug msg="completed challenge" Jan 13 19:24:17 volumio go-librespot[14764]: time="2026-01-13T19:24: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 13 19:24:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:24:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:24:17 volumio volumio[14568]: info: Plugin now_playing is not enabled Jan 13 19:24:17 volumio volumio[14568]: info: Loading plugin "outputs"... Jan 13 19:24:17 volumio volumio[14568]: info: Loading plugin "albumart"... Jan 13 19:24:17 volumio volumio[14568]: info: Plugin example_plugin is not enabled Jan 13 19:24:17 volumio volumio[14568]: info: Loading plugin "inputs"... Jan 13 19:24:17 volumio volumio[14568]: info: Loading plugin "updater_comm"... Jan 13 19:24:17 volumio volumio[14568]: info: Plugin mpdemulation is not enabled Jan 13 19:24:17 volumio volumio[14568]: info: Loading plugin "rest_api"... Jan 13 19:24:17 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.192.54 Jan 13 19:24:17 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:24:17 volumio avahi-daemon[664]: Registering new address record for 169.254.192.54 on eth0.IPv4. Jan 13 19:24:17 volumio volumio[14568]: info: Loading plugin "websocket"... Jan 13 19:24:18 volumio volumio[14568]: info: Starting Socket.io Server version 1.7.4 Jan 13 19:24:18 volumio volumio[14568]: info: Plugin fusiondsp is not enabled Jan 13 19:24:18 volumio volumio[14568]: info: Plugin mpdoutput is not enabled Jan 13 19:24:18 volumio volumio[14568]: info: Plugin RoonBridge is not enabled Jan 13 19:24:18 volumio volumio[14568]: info: Loading plugin "podcast"... Jan 13 19:24:18 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:18 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:18 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:18 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.192.54 Jan 13 19:24:18 volumio volumio[14568]: info: ControllerPodcast::constructor Jan 13 19:24:18 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.192.54 Jan 13 19:24:18 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.192.54 Jan 13 19:24:18 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:24:18 volumio avahi-daemon[664]: Withdrawing address record for 169.254.192.54 on eth0. Jan 13 19:24:18 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:18 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:18 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:18 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:24:18 volumio volumio[14568]: info: Loading plugin "volusonic"... Jan 13 19:24:18 volumio volumio[14771]: Forking 3 albumart workers Jan 13 19:24:19 volumio volumio-remote-updater[14193]: [2026-01-13 19:24:19] [connect] Successful connection Jan 13 19:24:19 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 19:24:20 volumio volumio[14568]: info: Applying required configuration parameters for plugin volusonic Jan 13 19:24:20 volumio volumio[14568]: info: Loading plugin "backup_restore"... Jan 13 19:24:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Jan 13 19:24:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:20 volumio go-librespot[14843]: go-librespot daemon starting... Jan 13 19:24:20 volumio go-librespot[14844]: time="2026-01-13T19:24:20-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:24:20 volumio go-librespot[14844]: time="2026-01-13T19:24:20-06:00" level=debug msg="app state loaded" Jan 13 19:24:20 volumio go-librespot[14844]: time="2026-01-13T19:24:20-06:00" level=debug msg="stored credentials not found" Jan 13 19:24:20 volumio go-librespot[14844]: time="2026-01-13T19:24:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:24:20 volumio volumio[14813]: Starting albumart workers Jan 13 19:24:21 volumio volumio[14815]: Starting albumart workers Jan 13 19:24:21 volumio volumio[14568]: info: Applying required configuration parameters for plugin backup_restore Jan 13 19:24:21 volumio volumio[14568]: info: Plugin rpi_eeprom_config is not enabled Jan 13 19:24:21 volumio volumio[14568]: info: Plugin rpi_eeprom_updater is not enabled Jan 13 19:24:21 volumio volumio[14568]: info: Loading plugin "scheduledrestart"... Jan 13 19:24:21 volumio volumio[14814]: Starting albumart workers Jan 13 19:24:21 volumio go-librespot[14844]: time="2026-01-13T19:24:21-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:24:21 volumio go-librespot[14844]: time="2026-01-13T19:24:21-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 13 19:24:21 volumio go-librespot[14844]: time="2026-01-13T19:24:21-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 13 19:24:21 volumio go-librespot[14844]: time="2026-01-13T19:24:21-06:00" level=info msg="zeroconf server listening on port 34145" Jan 13 19:24:21 volumio volumio[14568]: info: Applying required configuration parameters for plugin scheduledrestart Jan 13 19:24:21 volumio volumio[14568]: info: Plugin Bluetoothremote is not enabled Jan 13 19:24:21 volumio volumio[14568]: info: Plugin music_services_shield is not enabled Jan 13 19:24:21 volumio volumio[14568]: info: Loading plugin "Systeminfo"... Jan 13 19:24:21 volumio go-librespot[14844]: time="2026-01-13T19:24:21-06:00" level=debug msg="obtained new client token: AABn1ACT+/To+GmPnwfo/WqeAjyfEKyOe7RlnZbkik/huIalna/RckOPas2DaSchFyBRd9Hntb0nOjR2gSw4nwAgx86WgMWF7ci4mY8C9wkHA9wqIo0Ocl3PS1UYKKzOhsme615O5MQ2w/3RFCuGrnMhPufsAlGIpp0eeOtpAQiyt3PRQd7y27nsFVcbWp0l1ICq75BePz0S6CrZj6T+v+ZUAEGwuMzuoQfmVjman/Cgyu7Xz+MejqUONg==" Jan 13 19:24:21 volumio go-librespot[14844]: time="2026-01-13T19:24:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:24:21 volumio go-librespot[14844]: time="2026-01-13T19:24:21-06:00" level=debug msg="completed keyexchange" Jan 13 19:24:21 volumio go-librespot[14844]: time="2026-01-13T19:24:21-06:00" level=debug msg="completed challenge" Jan 13 19:24:21 volumio go-librespot[14844]: time="2026-01-13T19:24: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 13 19:24:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:24:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:24:22 volumio volumio[14568]: info: Plugin peppymeterbasic is not enabled Jan 13 19:24:22 volumio volumio[14568]: info: Loading plugin "peppyspectrum"... Jan 13 19:24:22 volumio volumio[14568]: info: Loading i18n strings for locale en Jan 13 19:24:22 volumio volumio[14568]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 19:24:22 volumio volumio[14568]: Updating browse sources language Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::initPlayerControls Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:24:22 volumio volumio[14568]: Express server listening on port 3000 Jan 13 19:24:22 volumio volumio[14568]: [Metrics] WebUI: 19s 81.17ms Jan 13 19:24:22 volumio volumio[14568]: info: CoreStateMachine::resetVolumioState Jan 13 19:24:22 volumio volumio[14568]: info: CoreStateMachine::getcurrentVolume Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:24:22 volumio sudo[14874]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 19:24:22 volumio sudo[14874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:22 volumio sudo[14874]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:22 volumio sudo[14876]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 19:24:22 volumio sudo[14876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:22 volumio sudo[14876]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:22 volumio volumio[14568]: info: Volumio Network Manager: Network status updated: 1 Jan 13 19:24:22 volumio volumio[14568]: info: VolumeController:: Volume=100 Mute =false Jan 13 19:24:22 volumio volumio[14568]: info: CoreStateMachine::pushState Jan 13 19:24:22 volumio volumio[14568]: info: CorePlayQueue::getTrack 0 Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::volumioPushState Jan 13 19:24:22 volumio volumio[14568]: info: CoreStateMachine::updateTrackBlock Jan 13 19:24:22 volumio volumio[14568]: info: CorePlayQueue::getTrackBlock Jan 13 19:24:22 volumio volumio[14568]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 19:24:23 volumio volumio-remote-updater[14193]: [2026-01-13 19:24:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768353859 101 Jan 13 19:24:23 volumio volumio[14568]: 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 13 19:24:23 volumio volumio[14568]: info: Reloading queue from file Jan 13 19:24:23 volumio volumio[14568]: info: CoreStateMachine::setRepeat null single undefined Jan 13 19:24:23 volumio volumio[14568]: info: CoreStateMachine::pushState Jan 13 19:24:23 volumio volumio[14568]: info: CorePlayQueue::getTrack 0 Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioPushState Jan 13 19:24:23 volumio volumio[14568]: info: CoreStateMachine::setRandom null Jan 13 19:24:23 volumio volumio[14568]: info: CoreStateMachine::pushState Jan 13 19:24:23 volumio volumio[14568]: info: CorePlayQueue::getTrack 0 Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioPushState Jan 13 19:24:23 volumio volumio[14568]: info: Setting Device type: Raspberry PI Jan 13 19:24:23 volumio volumio[14568]: info: VolumeController:: Volume=100 Mute =false Jan 13 19:24:23 volumio volumio[14568]: info: CoreStateMachine::pushState Jan 13 19:24:23 volumio volumio[14568]: info: CorePlayQueue::getTrack 0 Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioPushState Jan 13 19:24:23 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.79.164 Jan 13 19:24:23 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:24:23 volumio volumio[14568]: info: Completed loading Core Plugins Jan 13 19:24:23 volumio volumio[14568]: info: Preparing to generate the ALSA configuration file Jan 13 19:24:23 volumio avahi-daemon[664]: Registering new address record for 169.254.79.164 on eth0.IPv4. Jan 13 19:24:23 volumio sudo[14889]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 13 19:24:23 volumio sudo[14889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:23 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:23 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:23 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:23 volumio volumio[14568]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 19:24:23 volumio volumio[14568]: info: Discovery: Found device Volumio Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioGetState Jan 13 19:24:23 volumio volumio[14568]: info: CorePlayQueue::getTrack 0 Jan 13 19:24:23 volumio volumio[14568]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 19:24:23 volumio volumio[14568]: info: Reading ALSA contributions from plugins. Jan 13 19:24:23 volumio volumio[14568]: info: Asound.conf file unchanged, so no further update is needed Jan 13 19:24:23 volumio volumio[14568]: info: Output device has changed, restarting MPD Jan 13 19:24:23 volumio sudo[14889]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:23 volumio volumio[14568]: info: Output device has changed, restarting Shairport Sync Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:24:23 volumio sudo[14908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 19:24:23 volumio sudo[14908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:23 volumio sudo[14910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 19:24:23 volumio sudo[14910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:23 volumio sudo[14908]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:23 volumio volumio[14568]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:24:23 volumio volumio[14568]: info: ___________ START PLUGINS ___________ Jan 13 19:24:23 volumio volumio[14568]: info: ControllerMpd::onStart: Initializing MPD Jan 13 19:24:23 volumio volumio[14568]: info: Creating MPD Configuration file Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:24:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 13 19:24:23 volumio volumio[14568]: info: [1768353863328] CoreMusicLibrary::Adding element Media Servers Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:23 volumio sudo[14918]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 19:24:23 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.79.164 Jan 13 19:24:23 volumio sudo[14918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:23 volumio sudo[14920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 19:24:23 volumio sudo[14920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:23 volumio sudo[14918]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:24:23 volumio volumio[14568]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:24:23 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 19:24:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 19:24:23 volumio systemd[1]: mpd.service: Consumed 5.617s CPU time. Jan 13 19:24:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 19:24:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 19:24:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 19:24:23 volumio volumio[14568]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:24:23 volumio volumio[14568]: info: [1768353863460] CoreMusicLibrary::Adding element Last_100 Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:24:23 volumio volumio[14568]: info: [1768353863464] CoreMusicLibrary::Adding element Webradio Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 19:24:23 volumio volumio[14568]: info: Initializing BBC Radios Jan 13 19:24:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 19:24:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:24:23 volumio volumio[14568]: info: [1768353863541] CoreMusicLibrary::Adding element Bandcamp Discover Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Bandcamp Discover Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:24:23 volumio volumio[14568]: info: [1768353863554] CoreMusicLibrary::Adding element SoundCloud Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Bandcamp Discover Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source SoundCloud Jan 13 19:24:23 volumio volumio[14568]: info: Creating Spotify config file Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:23 volumio sudo[14941]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 19:24:23 volumio sudo[14941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 19:24:23 volumio sudo[14941]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:23 volumio volumio[14568]: info: [squeezelite_mc] Starting proxy server... Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:24:23 volumio volumio[14568]: info: [1768353863913] CoreMusicLibrary::Adding element YouTube2 Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Bandcamp Discover Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source SoundCloud Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube2 Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:24:23 volumio volumio[14568]: info: [1768353863931] CoreMusicLibrary::Adding element YouTube Music Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Bandcamp Discover Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source SoundCloud Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube2 Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube Music Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:24:23 volumio volumio[14568]: info: [1768353863943] CoreMusicLibrary::Adding element Podcast Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Bandcamp Discover Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source SoundCloud Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube2 Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube Music Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Podcast Jan 13 19:24:23 volumio volumio[14568]: info: Loading i18n strings for locale en Jan 13 19:24:23 volumio volumio[14568]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 19:24:23 volumio volumio[14568]: Updating browse sources language Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Bandcamp Discover Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source SoundCloud Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube2 Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube Music Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Podcast Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Bandcamp Discover Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source SoundCloud Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube2 Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube Music Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Podcast Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:24:23 volumio volumio[14568]: info: [1768353863992] CoreMusicLibrary::Adding element Volusonic Jan 13 19:24:23 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Bandcamp Discover Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source SoundCloud Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube2 Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source YouTube Music Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Podcast Jan 13 19:24:23 volumio volumio[14568]: Cannot find translation for source Volusonic Jan 13 19:24:23 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.79.164 Jan 13 19:24:23 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.79.164 Jan 13 19:24:23 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:24:24 volumio avahi-daemon[664]: Withdrawing address record for 169.254.79.164 on eth0. Jan 13 19:24:24 volumio volumio[14568]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 13 19:24:24 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:24 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:24 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:24 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 13 19:24:24 volumio volumio[14568]: info: Volumio Calling Home Jan 13 19:24:24 volumio volumio[14568]: info: [squeezelite_mc] Proxy server started on port 44649 Jan 13 19:24:24 volumio volumio[14568]: info: Preparing to generate the ALSA configuration file Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 19:24:24 volumio volumio[14568]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 19:24:24 volumio volumio[14568]: info: Discovery: Found device Volumio Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::volumioGetState Jan 13 19:24:24 volumio volumio[14568]: info: CorePlayQueue::getTrack 0 Jan 13 19:24:24 volumio volumio[14568]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 19:24:24 volumio volumio[14568]: info: Reading ALSA contributions from plugins. Jan 13 19:24:24 volumio volumio[14568]: info: MPD Permissions set Jan 13 19:24:24 volumio volumio[14568]: info: MPD Permissions set Jan 13 19:24:24 volumio volumio[14568]: info: Upmpdcli Daemon Started Jan 13 19:24:24 volumio volumio[14568]: info: Spotify config file written Jan 13 19:24:24 volumio sudo[14970]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 13 19:24:24 volumio sudo[14970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:24 volumio volumio[14568]: 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 13 19:24:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:24 volumio volumio[14568]: info: VolumeController:: Volume=100 Mute =false Jan 13 19:24:24 volumio volumio[14568]: info: CoreStateMachine::pushState Jan 13 19:24:24 volumio volumio[14568]: info: CorePlayQueue::getTrack 0 Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::volumioPushState Jan 13 19:24:24 volumio volumio[14568]: info: [squeezelite_mc] Server discovery started Jan 13 19:24:24 volumio volumio[14568]: info: [squeezelite_mc] Player finder started Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio go-librespot[14972]: go-librespot daemon starting... Jan 13 19:24:24 volumio sudo[14970]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:24 volumio volumio[14568]: info: No need to fix Spotify hosts Jan 13 19:24:24 volumio go-librespot[14981]: time="2026-01-13T19:24:24-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:24:24 volumio go-librespot[14981]: time="2026-01-13T19:24:24-06:00" level=debug msg="app state loaded" Jan 13 19:24:24 volumio go-librespot[14981]: time="2026-01-13T19:24:24-06:00" level=debug msg="stored credentials not found" Jan 13 19:24:24 volumio go-librespot[14981]: time="2026-01-13T19:24:24-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:24:24 volumio volumio[14568]: 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 13 19:24:24 volumio volumio[14568]: info: Volumio called home Jan 13 19:24:24 volumio volumio[14568]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 13 19:24:24 volumio volumio[14568]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 13 19:24:24 volumio volumio[14568]: 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 13 19:24:24 volumio volumio[14568]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 19:24:24 volumio volumio[14568]: SPOTIFY: BQB4PkRiJB_GU_x-TJiF1cUbTXOvdknUI2eMd68E5goA0ipr_abYyZUWyTv48prg_aeKtil25uip76ukWnpsjT5Kq9m0fZHKpczVvoIhuDKsIYCAOlca6Hru10u4U4JUH2t3fWWdCAbtq44UQMNrCUU8ML-wh7n1qp7S7X2GJWhTUA2cpkYjEqwcNIFD1D9gEljNRzmqkkyEe8DiKoECWhMPY2umFeGYRn7Vuq4 Jan 13 19:24:24 volumio volumio[14568]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 19:24:24 volumio volumio[14568]: info: New Spotify access token = BQB4PkRiJB_GU_x-TJiF1cUbTXOvdknUI2eMd68E5goA0ipr_abYyZUWyTv48prg_aeKtil25uip76ukWnpsjT5Kq9m0fZHKpczVvoIhuDKsIYCAOlca6Hru10u4U4JUH2t3fWWdCAbtq44UQMNrCUU8ML-wh7n1qp7S7X2GJWhTUA2cpkYjEqwcNIFD1D9gEljNRzmqkkyEe8DiKoECWhMPY2umFeGYRn7Vuq4 Jan 13 19:24:24 volumio volumio[14568]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 13 19:24:24 volumio go-librespot[14981]: time="2026-01-13T19:24: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:24:24 volumio go-librespot[14981]: time="2026-01-13T19:24:24-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 13 19:24:24 volumio go-librespot[14981]: time="2026-01-13T19:24:24-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 13 19:24:24 volumio go-librespot[14981]: time="2026-01-13T19:24:24-06:00" level=info msg="zeroconf server listening on port 40491" Jan 13 19:24:24 volumio volumio[14568]: info: Starting Shairport Sync Jan 13 19:24:25 volumio volumio[14568]: info: Starting Shairport Sync Jan 13 19:24:25 volumio volumio[14568]: info: Starting Shairport Sync Jan 13 19:24:25 volumio sudo[14997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:24:25 volumio sudo[14997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:25 volumio sudo[15000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:24:25 volumio sudo[15000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:25 volumio sudo[15002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:24:25 volumio sudo[15002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:25 volumio sudo[14994]: 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 13 19:24:25 volumio sudo[14994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:25 volumio sudo[14994]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:25 volumio volumio[14568]: info: Asound.conf file unchanged, so no further update is needed Jan 13 19:24:25 volumio volumio[14568]: info: Output device has changed, restarting MPD Jan 13 19:24:25 volumio go-librespot[14981]: time="2026-01-13T19:24:25-06:00" level=debug msg="obtained new client token: AABCl/D6lXDu5zj1+gnE+M4jJ8SRfCquPm5jU7aY5rQDQ1hgns6z8bS9fCUOIeYRQebXweBx4h+CnT5VI+3lL38WcHF9c64Egwb4qxNqPllbixkttkUZf9GzHVq+8DFjUwI11LV6MfDJC7ifEDEkFQM5HW25/dOwLMFbACGb3izZ5ekiIEhP2ySbIwRs2A/UBB++JDTMjkjhiYeEZYr1dkSnyV42MKR6zIl09AhvYTp7D2K72wYvJP0=" Jan 13 19:24:25 volumio volumio[14568]: info: Output device has changed, restarting Shairport Sync Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:24:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 19:24:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 19:24:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:24:25 volumio systemd[1]: shairport-sync.service: Consumed 2.071s CPU time. Jan 13 19:24:25 volumio go-librespot[14981]: time="2026-01-13T19:24:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:24:25 volumio sudo[15007]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 19:24:25 volumio sudo[15007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:25 volumio sudo[15009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 19:24:25 volumio sudo[15009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:25 volumio sudo[15007]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:25 volumio volumio[14568]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 19:24:25 volumio go-librespot[14981]: time="2026-01-13T19:24:25-06:00" level=debug msg="completed keyexchange" Jan 13 19:24:25 volumio go-librespot[14981]: time="2026-01-13T19:24:25-06:00" level=debug msg="completed challenge" Jan 13 19:24:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:24:25 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 19:24:25 volumio sudo[15002]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:25 volumio sudo[14997]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:25 volumio sudo[15000]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:25 volumio go-librespot[14981]: time="2026-01-13T19:24: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 13 19:24:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:24:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:24:25 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 19:24:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 19:24:25 volumio systemd[1]: mpd.service: Consumed 1.702s CPU time. Jan 13 19:24:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 19:24:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 19:24:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 19:24:25 volumio volumio[14568]: info: MPD Permissions set Jan 13 19:24:25 volumio volumio[14568]: info: Shairport-Sync Started Jan 13 19:24:25 volumio volumio[14568]: Error adding Membership: Error: addMembership EINVAL Jan 13 19:24:25 volumio volumio[14568]: info: Shairport-Sync Started Jan 13 19:24:25 volumio volumio[14568]: info: Shairport-Sync Started Jan 13 19:24:25 volumio volumio[14568]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 13 19:24:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 19:24:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 19:24:25 volumio sudo[15039]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 13 19:24:25 volumio sudo[15039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:25 volumio sudo[15039]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:25 volumio volumio[14568]: 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 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:25 volumio volumio[14568]: info: CoreCommandRouter::volumioGetState Jan 13 19:24:25 volumio volumio[14568]: info: CorePlayQueue::getTrack 0 Jan 13 19:24:25 volumio volumio[14568]: info: Starting Shairport Sync Jan 13 19:24:25 volumio sudo[15045]: 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 13 19:24:25 volumio sudo[15045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:25 volumio sudo[15045]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:25 volumio sudo[15041]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 19:24:25 volumio sudo[15041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 19:24:25 volumio sudo[15041]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:25 volumio sudo[15053]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 19:24:25 volumio sudo[15053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:25 volumio volumio[14568]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 13 19:24:25 volumio sudo[15058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 13 19:24:25 volumio sudo[15058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 19:24:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 19:24:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 19:24:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:24:26 volumio systemd[1]: Reloading. Jan 13 19:24:26 volumio volumio[14568]: 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 13 19:24:26 volumio volumio[14568]: info: Spotify Successfully logged in Jan 13 19:24:26 volumio volumio[14568]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 19:24:26 volumio volumio[14568]: info: [1768353866050] CoreMusicLibrary::Adding element Spotify Jan 13 19:24:26 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 19:24:26 volumio volumio[14568]: Cannot find translation for source Bandcamp Discover Jan 13 19:24:26 volumio volumio[14568]: Cannot find translation for source SoundCloud Jan 13 19:24:26 volumio volumio[14568]: Cannot find translation for source YouTube2 Jan 13 19:24:26 volumio volumio[14568]: Cannot find translation for source YouTube Music Jan 13 19:24:26 volumio volumio[14568]: Cannot find translation for source Podcast Jan 13 19:24:26 volumio volumio[14568]: Cannot find translation for source Volusonic Jan 13 19:24:26 volumio volumio[14568]: Cannot find translation for source Spotify Jan 13 19:24:26 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:26 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:26 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 19:24:26 volumio volumio[14568]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 19:24:27 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 19:24:27 volumio volumio[14568]: info: go-librespot daemon successfully initialized Jan 13 19:24:28 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 13 19:24:28 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 13 19:24:28 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.80.18 Jan 13 19:24:28 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 19:24:28 volumio avahi-daemon[664]: Registering new address record for 169.254.80.18 on eth0.IPv4. Jan 13 19:24:29 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.80.18 Jan 13 19:24:29 volumio volumio[14568]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 19:24:29 volumio volumio[14568]: Error: addMembership ENODEV Jan 13 19:24:29 volumio volumio[14568]: at Socket.addMembership (node:dgram:860:11) Jan 13 19:24:29 volumio volumio[14568]: at addMembership (/volumio/node_modules/node-ssdp/lib/index.js:264:16) { Jan 13 19:24:29 volumio volumio[14568]: errno: -19, Jan 13 19:24:29 volumio volumio[14568]: code: 'ENODEV', Jan 13 19:24:29 volumio volumio[14568]: syscall: 'addMembership' Jan 13 19:24:29 volumio volumio[14568]: } Jan 13 19:24:29 volumio volumio[14568]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 19:24:29 volumio sudo[15058]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Jan 13 19:24:29 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:29 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:29 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:29 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.80.18 Jan 13 19:24:29 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.80.18 Jan 13 19:24:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 19:24:29 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 19:24:29 volumio go-librespot[15118]: go-librespot daemon starting... Jan 13 19:24:29 volumio avahi-daemon[664]: Withdrawing address record for 169.254.80.18 on eth0. Jan 13 19:24:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 19:24:29 volumio sudo[15053]: pam_unix(sudo:session): session closed for user root Jan 13 19:24:29 volumio go-librespot[15121]: time="2026-01-13T19:24:29-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 19:24:29 volumio go-librespot[15121]: time="2026-01-13T19:24:29-06:00" level=debug msg="app state loaded" Jan 13 19:24:29 volumio go-librespot[15121]: time="2026-01-13T19:24:29-06:00" level=debug msg="stored credentials not found" Jan 13 19:24:29 volumio go-librespot[15121]: time="2026-01-13T19:24:29-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 19:24:29 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:29 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 19:24:29 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 19:24:29 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 19:24:29 volumio go-librespot[15121]: time="2026-01-13T19:24:29-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 19:24:29 volumio go-librespot[15121]: time="2026-01-13T19:24:29-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 13 19:24:29 volumio go-librespot[15121]: time="2026-01-13T19:24:29-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 13 19:24:29 volumio go-librespot[15121]: time="2026-01-13T19:24:29-06:00" level=info msg="zeroconf server listening on port 40991" Jan 13 19:24:30 volumio go-librespot[15121]: time="2026-01-13T19:24:30-06:00" level=debug msg="obtained new client token: AABu1Q2g5iQq3sJBfCodEA5gp57WemB+lxO4uiOEgoroaCGc8skfYMWuKEdqbpB7byWMFZ4McN2Kht2RAEeQLk6SqAsifi48/wWWhfb0g9K+TVsDHDNKMl0SoGfjsuItYaCVt4N9E8jid2l+Qga9DxAe5qcj1XuunKte3ccMm1Xgrr+N6WCbE5McCVr2IrOx0dCJ4zuobKGjgjwxZQjpKQAJXkk399TEUGfZpEESTH3sog2LDKRfXDE=" Jan 13 19:24:30 volumio go-librespot[15121]: time="2026-01-13T19:24:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 19:24:30 volumio go-librespot[15121]: time="2026-01-13T19:24:30-06:00" level=debug msg="completed keyexchange" Jan 13 19:24:30 volumio go-librespot[15121]: time="2026-01-13T19:24:30-06:00" level=debug msg="completed challenge" Jan 13 19:24:30 volumio go-librespot[15121]: time="2026-01-13T19:24:30-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 13 19:24:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 19:24:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 19:24:30 volumio sudo[15160]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-13 19:23' Jan 13 19:24:30 volumio sudo[15160]: 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"