Jan 13 17:06:00 volumio volumio[30121]: info: Loading plugin "youtube2"... Jan 13 17:06:00 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.125.56 Jan 13 17:06:00 volumio avahi-daemon[664]: Registering new address record for 169.254.125.56 on eth0.IPv4. Jan 13 17:06:00 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:06:00 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:00 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:00 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.125.56 Jan 13 17:06:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.125.56 Jan 13 17:06:00 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.125.56 Jan 13 17:06:00 volumio avahi-daemon[664]: Withdrawing address record for 169.254.125.56 on eth0. Jan 13 17:06:00 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:06:00 volumio volumio[30121]: info: Loading plugin "ytcr"... Jan 13 17:06:00 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:06:00 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:00 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:00 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 13 17:06:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:01 volumio go-librespot[30283]: go-librespot daemon starting... Jan 13 17:06:01 volumio go-librespot[30284]: time="2026-01-13T17:06:01-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:01 volumio go-librespot[30284]: time="2026-01-13T17:06:01-06:00" level=debug msg="app state loaded" Jan 13 17:06:01 volumio go-librespot[30284]: time="2026-01-13T17:06:01-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:01 volumio go-librespot[30284]: time="2026-01-13T17:06:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:01 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 17:06:02 volumio go-librespot[30284]: time="2026-01-13T17:06:02-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 17:06:02 volumio go-librespot[30284]: time="2026-01-13T17:06:02-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 17:06:02 volumio go-librespot[30284]: time="2026-01-13T17:06:02-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 17:06:02 volumio go-librespot[30284]: time="2026-01-13T17:06:02-06:00" level=info msg="zeroconf server listening on port 36721" Jan 13 17:06:02 volumio go-librespot[30284]: time="2026-01-13T17:06:02-06:00" level=debug msg="obtained new client token: AAA/VBHBNidG/lmjg5Vvkh8W3lULpY06CfqzyjnkYNgBNWTcmOrnKNblcPSNGbDafiCPeDAz1PI5DSyftbBY6Gy2Z6SirhE5HmQdM2PHRaZfv99I99g7SnKQpoaBjDActsTIjUH6iWQ6hnscgHIycMIz0r+r16JW1oe48JMcsvXv1IZR77gYJ9+UJykM8JWwKKfiEMGTakgAAssLqId1rX4PZzCFw67k8jHjtByMWE2Q0KSSLdCqoVZg6A==" Jan 13 17:06:02 volumio go-librespot[30284]: time="2026-01-13T17:06:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:02 volumio go-librespot[30284]: time="2026-01-13T17:06:02-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:02 volumio go-librespot[30284]: time="2026-01-13T17:06:02-06:00" level=debug msg="completed challenge" Jan 13 17:06:03 volumio go-librespot[30284]: time="2026-01-13T17:06: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 17:06:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:03 volumio volumio[30121]: info: Loading plugin "ytmusic"... Jan 13 17:06:04 volumio volumio[30121]: info: Plugin now_playing is not enabled Jan 13 17:06:04 volumio volumio[30121]: info: Loading plugin "outputs"... Jan 13 17:06:04 volumio volumio[30121]: info: Loading plugin "albumart"... Jan 13 17:06:04 volumio volumio[30121]: info: Plugin example_plugin is not enabled Jan 13 17:06:04 volumio volumio[30121]: info: Loading plugin "inputs"... Jan 13 17:06:04 volumio volumio[30121]: info: Loading plugin "updater_comm"... Jan 13 17:06:04 volumio volumio[30121]: info: Plugin mpdemulation is not enabled Jan 13 17:06:04 volumio volumio[30121]: info: Loading plugin "rest_api"... Jan 13 17:06:04 volumio volumio[30121]: info: Loading plugin "websocket"... Jan 13 17:06:04 volumio volumio[30121]: info: Starting Socket.io Server version 1.7.4 Jan 13 17:06:04 volumio volumio[30121]: info: Plugin fusiondsp is not enabled Jan 13 17:06:04 volumio volumio[30121]: info: Plugin mpdoutput is not enabled Jan 13 17:06:04 volumio volumio[30121]: info: Plugin RoonBridge is not enabled Jan 13 17:06:04 volumio volumio[30121]: info: Loading plugin "podcast"... Jan 13 17:06:04 volumio volumio[30121]: info: ControllerPodcast::constructor Jan 13 17:06:04 volumio volumio[30121]: info: Loading plugin "volusonic"... Jan 13 17:06:04 volumio volumio[30310]: Forking 3 albumart workers Jan 13 17:06:05 volumio volumio-remote-updater[14193]: [2026-01-13 17:06:05] [connect] Successful connection Jan 13 17:06:05 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.131.95 Jan 13 17:06:05 volumio avahi-daemon[664]: Registering new address record for 169.254.131.95 on eth0.IPv4. Jan 13 17:06:05 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:06:05 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:05 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:05 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 13 17:06:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:06 volumio go-librespot[30366]: go-librespot daemon starting... Jan 13 17:06:06 volumio go-librespot[30367]: time="2026-01-13T17:06:06-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:06 volumio go-librespot[30367]: time="2026-01-13T17:06:06-06:00" level=debug msg="app state loaded" Jan 13 17:06:06 volumio go-librespot[30367]: time="2026-01-13T17:06:06-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:06 volumio go-librespot[30367]: time="2026-01-13T17:06:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.131.95 Jan 13 17:06:06 volumio volumio[30121]: info: Applying required configuration parameters for plugin volusonic Jan 13 17:06:06 volumio volumio[30121]: info: Loading plugin "backup_restore"... Jan 13 17:06:07 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.131.95 Jan 13 17:06:07 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.131.95 Jan 13 17:06:07 volumio avahi-daemon[664]: Withdrawing address record for 169.254.131.95 on eth0. Jan 13 17:06:07 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:06:07 volumio go-librespot[30367]: time="2026-01-13T17:06: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 17:06:07 volumio go-librespot[30367]: time="2026-01-13T17:06: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 17:06:07 volumio go-librespot[30367]: time="2026-01-13T17:06: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 17:06:07 volumio go-librespot[30367]: time="2026-01-13T17:06:07-06:00" level=info msg="zeroconf server listening on port 37763" Jan 13 17:06:07 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:07 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:07 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:07 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:06:07 volumio go-librespot[30367]: time="2026-01-13T17:06:07-06:00" level=debug msg="obtained new client token: AAAGSenwi+5LyAPJPenqPByW1cMbmcjik4L4l1s2Bt2oLTFB+MSzmYYuVQIigu3Qw82y4OfVA7tq2oYH4VTKAtcRtp5cSbAvgXVByLXcraxykThV/uYZPsvgHH7Og2LiCj2z52t8KpcQzpDfhJ4r2eQSq3YqgTmtm2DxbAh3jTMVZttmUsXeNBHpui3mPNIiJP97omWOHjDhTFJoju2ohSQc0vJar5y0Xru7fl1sGmsrhziSvsIqwfaovw==" Jan 13 17:06:07 volumio volumio[30321]: Starting albumart workers Jan 13 17:06:07 volumio volumio[30320]: Starting albumart workers Jan 13 17:06:07 volumio go-librespot[30367]: time="2026-01-13T17:06:07-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:07 volumio volumio[30322]: Starting albumart workers Jan 13 17:06:07 volumio volumio[30121]: info: Applying required configuration parameters for plugin backup_restore Jan 13 17:06:07 volumio volumio[30121]: info: Plugin rpi_eeprom_config is not enabled Jan 13 17:06:07 volumio volumio[30121]: info: Plugin rpi_eeprom_updater is not enabled Jan 13 17:06:07 volumio volumio[30121]: info: Loading plugin "scheduledrestart"... Jan 13 17:06:07 volumio go-librespot[30367]: time="2026-01-13T17:06:07-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:07 volumio go-librespot[30367]: time="2026-01-13T17:06:07-06:00" level=debug msg="completed challenge" Jan 13 17:06:07 volumio go-librespot[30367]: time="2026-01-13T17:06:07-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 17:06:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:08 volumio volumio[30121]: info: Applying required configuration parameters for plugin scheduledrestart Jan 13 17:06:08 volumio volumio[30121]: info: Plugin Bluetoothremote is not enabled Jan 13 17:06:08 volumio volumio[30121]: info: Plugin music_services_shield is not enabled Jan 13 17:06:08 volumio volumio[30121]: info: Loading plugin "Systeminfo"... Jan 13 17:06:08 volumio volumio[30121]: info: Plugin peppymeterbasic is not enabled Jan 13 17:06:08 volumio volumio[30121]: info: Loading plugin "peppyspectrum"... Jan 13 17:06:09 volumio volumio[30121]: info: Loading i18n strings for locale en Jan 13 17:06:09 volumio volumio[30121]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 17:06:09 volumio volumio[30121]: Updating browse sources language Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::initPlayerControls Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: Express server listening on port 3000 Jan 13 17:06:09 volumio volumio[30121]: [Metrics] WebUI: 19s 126.83ms Jan 13 17:06:09 volumio volumio[30121]: info: CoreStateMachine::resetVolumioState Jan 13 17:06:09 volumio volumio[30121]: info: CoreStateMachine::getcurrentVolume Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:09 volumio sudo[30413]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 17:06:09 volumio sudo[30413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:09 volumio sudo[30413]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:09 volumio sudo[30415]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 17:06:09 volumio sudo[30415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:09 volumio sudo[30415]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:09 volumio volumio[30121]: info: Volumio Network Manager: Network status updated: 1 Jan 13 17:06:09 volumio volumio[30121]: info: VolumeController:: Volume=100 Mute =false Jan 13 17:06:09 volumio volumio[30121]: info: CoreStateMachine::pushState Jan 13 17:06:09 volumio volumio[30121]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::volumioPushState Jan 13 17:06:09 volumio volumio[30121]: info: CoreStateMachine::updateTrackBlock Jan 13 17:06:09 volumio volumio[30121]: info: CorePlayQueue::getTrackBlock Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 17:06:09 volumio volumio-remote-updater[14193]: [2026-01-13 17:06:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768345565 101 Jan 13 17:06:09 volumio volumio[30121]: 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 17:06:09 volumio volumio[30121]: info: Reloading queue from file Jan 13 17:06:09 volumio volumio[30121]: info: CoreStateMachine::setRepeat null single undefined Jan 13 17:06:09 volumio volumio[30121]: info: CoreStateMachine::pushState Jan 13 17:06:09 volumio volumio[30121]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::volumioPushState Jan 13 17:06:09 volumio volumio[30121]: info: CoreStateMachine::setRandom null Jan 13 17:06:09 volumio volumio[30121]: info: CoreStateMachine::pushState Jan 13 17:06:09 volumio volumio[30121]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::volumioPushState Jan 13 17:06:09 volumio volumio[30121]: info: Setting Device type: Raspberry PI Jan 13 17:06:09 volumio volumio[30121]: info: VolumeController:: Volume=100 Mute =false Jan 13 17:06:09 volumio volumio[30121]: info: CoreStateMachine::pushState Jan 13 17:06:09 volumio volumio[30121]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::volumioPushState Jan 13 17:06:09 volumio volumio[30121]: info: Completed loading Core Plugins Jan 13 17:06:09 volumio volumio[30121]: info: Preparing to generate the ALSA configuration file Jan 13 17:06:09 volumio sudo[30429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 13 17:06:09 volumio sudo[30429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:09 volumio volumio[30121]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 17:06:09 volumio volumio[30121]: info: Discovery: Found device Volumio Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::volumioGetState Jan 13 17:06:09 volumio volumio[30121]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:09 volumio volumio[30121]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 17:06:09 volumio volumio[30121]: info: Discovery: Found device Volumio Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::volumioGetState Jan 13 17:06:09 volumio volumio[30121]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:09 volumio volumio[30121]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 17:06:09 volumio volumio[30121]: info: Reading ALSA contributions from plugins. Jan 13 17:06:09 volumio sudo[30429]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:09 volumio volumio[30121]: info: Upmpdcli Daemon Started Jan 13 17:06:09 volumio volumio[30121]: info: Asound.conf file unchanged, so no further update is needed Jan 13 17:06:09 volumio volumio[30121]: info: Output device has changed, restarting MPD Jan 13 17:06:09 volumio volumio[30121]: info: Output device has changed, restarting Shairport Sync Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:09 volumio sudo[30432]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 17:06:09 volumio sudo[30432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:09 volumio sudo[30432]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:09 volumio sudo[30434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 17:06:09 volumio sudo[30434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:09 volumio volumio[30121]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:06:09 volumio volumio[30121]: info: ___________ START PLUGINS ___________ Jan 13 17:06:09 volumio volumio[30121]: info: ControllerMpd::onStart: Initializing MPD Jan 13 17:06:09 volumio volumio[30121]: info: Creating MPD Configuration file Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:09 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 13 17:06:09 volumio sudo[30444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 17:06:09 volumio volumio[30121]: info: [1768345569895] CoreMusicLibrary::Adding element Media Servers Jan 13 17:06:09 volumio sudo[30444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:09 volumio sudo[30442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:09 volumio sudo[30442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:09 volumio sudo[30442]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:09 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:09 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 17:06:09 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 17:06:09 volumio systemd[1]: mpd.service: Consumed 5.534s CPU time. Jan 13 17:06:09 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 17:06:09 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 17:06:09 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 17:06:10 volumio volumio[30121]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:10 volumio volumio[30121]: info: [1768345570011] CoreMusicLibrary::Adding element Last_100 Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:10 volumio volumio[30121]: info: [1768345570015] CoreMusicLibrary::Adding element Webradio Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 17:06:10 volumio volumio[30121]: info: Initializing BBC Radios Jan 13 17:06:10 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 17:06:10 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:10 volumio volumio[30121]: info: [1768345570094] CoreMusicLibrary::Adding element Bandcamp Discover Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:10 volumio volumio[30121]: info: [1768345570106] CoreMusicLibrary::Adding element SoundCloud Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source SoundCloud Jan 13 17:06:10 volumio volumio[30121]: info: Creating Spotify config file Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio sudo[30464]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 17:06:10 volumio sudo[30464]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 17:06:10 volumio sudo[30464]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:10 volumio volumio[30121]: info: [squeezelite_mc] Starting proxy server... Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:10 volumio volumio[30121]: info: [1768345570473] CoreMusicLibrary::Adding element YouTube2 Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source SoundCloud Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube2 Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:10 volumio volumio[30121]: info: [1768345570492] CoreMusicLibrary::Adding element YouTube Music Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source SoundCloud Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube2 Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube Music Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:10 volumio volumio[30121]: info: [1768345570503] CoreMusicLibrary::Adding element Podcast Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source SoundCloud Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube2 Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube Music Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Podcast Jan 13 17:06:10 volumio volumio[30121]: info: Loading i18n strings for locale en Jan 13 17:06:10 volumio volumio[30121]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 17:06:10 volumio volumio[30121]: Updating browse sources language Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source SoundCloud Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube2 Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube Music Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Podcast Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source SoundCloud Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube2 Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube Music Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Podcast Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:10 volumio volumio[30121]: info: [1768345570550] CoreMusicLibrary::Adding element Volusonic Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source SoundCloud Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube2 Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source YouTube Music Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Podcast Jan 13 17:06:10 volumio volumio[30121]: Cannot find translation for source Volusonic Jan 13 17:06:10 volumio volumio[30121]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 13 17:06:10 volumio volumio[30121]: info: Volumio Calling Home Jan 13 17:06:10 volumio volumio[30121]: info: [squeezelite_mc] Proxy server started on port 36031 Jan 13 17:06:10 volumio volumio[30121]: info: Preparing to generate the ALSA configuration file Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 17:06:10 volumio volumio[30121]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 17:06:10 volumio volumio[30121]: info: Reading ALSA contributions from plugins. Jan 13 17:06:10 volumio volumio[30121]: info: MPD Permissions set Jan 13 17:06:10 volumio volumio[30121]: info: MPD Permissions set Jan 13 17:06:10 volumio volumio[30121]: info: Spotify config file written Jan 13 17:06:10 volumio sudo[30479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 13 17:06:10 volumio sudo[30479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:10 volumio volumio[30121]: 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 17:06:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jan 13 17:06:10 volumio volumio[30121]: info: VolumeController:: Volume=100 Mute =false Jan 13 17:06:10 volumio volumio[30121]: info: CoreStateMachine::pushState Jan 13 17:06:10 volumio volumio[30121]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::volumioPushState Jan 13 17:06:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:10 volumio volumio[30121]: info: [squeezelite_mc] Server discovery started Jan 13 17:06:10 volumio volumio[30121]: info: [squeezelite_mc] Player finder started Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:10 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio go-librespot[30481]: go-librespot daemon starting... Jan 13 17:06:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 13 17:06:11 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 13 17:06:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:11 volumio volumio[30121]: info: No need to fix Spotify hosts Jan 13 17:06:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:11 volumio go-librespot[30500]: go-librespot daemon starting... Jan 13 17:06:11 volumio sudo[30479]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:11 volumio go-librespot[30501]: time="2026-01-13T17:06:11-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:11 volumio go-librespot[30501]: time="2026-01-13T17:06:11-06:00" level=debug msg="app state loaded" Jan 13 17:06:11 volumio go-librespot[30501]: time="2026-01-13T17:06:11-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:11 volumio go-librespot[30501]: time="2026-01-13T17:06:11-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:11 volumio volumio[30121]: 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 17:06:11 volumio volumio[30121]: info: Volumio called home Jan 13 17:06:11 volumio volumio[30121]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 13 17:06:11 volumio volumio[30121]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 13 17:06:11 volumio volumio[30121]: 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 17:06:11 volumio volumio[30121]: info: Starting Shairport Sync Jan 13 17:06:11 volumio volumio[30121]: info: Starting Shairport Sync Jan 13 17:06:11 volumio volumio[30121]: info: Starting Shairport Sync Jan 13 17:06:11 volumio sudo[30513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:06:11 volumio sudo[30513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:11 volumio sudo[30516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:06:11 volumio volumio[30121]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 17:06:11 volumio volumio[30121]: SPOTIFY: BQC_vsL2SnIoUgfkRmGDWi1Bkq9ENfXmPyz8QrEG7N8c6Po4n7C9wg7cOuDvUPCkT2C-IKkzkPASkWD4Ypm2rf0f0P1fK8bOjo9pFJzm3Jg_-Lxj_tupeZ7TiPs0vqhRBQIPgL6pUmcbdsCmBkLqhUxje0zSxejxchBpxcf0Pl3xTcnbYYLVKSr3IM4G4PARiV-QKm1x3ffBUgBri7UVs5cZw0v-bVXBrix-vyY Jan 13 17:06:11 volumio volumio[30121]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 17:06:11 volumio sudo[30516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:11 volumio volumio[30121]: info: New Spotify access token = BQC_vsL2SnIoUgfkRmGDWi1Bkq9ENfXmPyz8QrEG7N8c6Po4n7C9wg7cOuDvUPCkT2C-IKkzkPASkWD4Ypm2rf0f0P1fK8bOjo9pFJzm3Jg_-Lxj_tupeZ7TiPs0vqhRBQIPgL6pUmcbdsCmBkLqhUxje0zSxejxchBpxcf0Pl3xTcnbYYLVKSr3IM4G4PARiV-QKm1x3ffBUgBri7UVs5cZw0v-bVXBrix-vyY Jan 13 17:06:11 volumio volumio[30121]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 13 17:06:11 volumio sudo[30518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:06:11 volumio sudo[30518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:11 volumio sudo[30510]: 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 17:06:11 volumio sudo[30510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:11 volumio sudo[30510]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 17:06:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 17:06:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:06:11 volumio systemd[1]: shairport-sync.service: Consumed 1.962s CPU time. Jan 13 17:06:11 volumio volumio[30121]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 13 17:06:11 volumio volumio[30121]: info: Asound.conf file unchanged, so no further update is needed Jan 13 17:06:11 volumio volumio[30121]: info: Output device has changed, restarting MPD Jan 13 17:06:11 volumio volumio[30121]: info: Output device has changed, restarting Shairport Sync Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:11 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:11 volumio sudo[30525]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 13 17:06:11 volumio sudo[30525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:06:11 volumio go-librespot[30501]: time="2026-01-13T17:06:11-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 17:06:11 volumio go-librespot[30501]: time="2026-01-13T17:06:11-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 17:06:11 volumio go-librespot[30501]: time="2026-01-13T17:06:11-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 17:06:11 volumio sudo[30516]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:11 volumio sudo[30518]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:11 volumio sudo[30525]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:11 volumio go-librespot[30501]: time="2026-01-13T17:06:11-06:00" level=info msg="zeroconf server listening on port 36995" Jan 13 17:06:11 volumio sudo[30513]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:11 volumio sudo[30527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 17:06:11 volumio sudo[30527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:11 volumio volumio[30121]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:06:11 volumio sudo[30527]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:11 volumio sudo[30529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 17:06:11 volumio sudo[30529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:11 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 17:06:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 17:06:11 volumio systemd[1]: mpd.service: Consumed 1.700s CPU time. Jan 13 17:06:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 17:06:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 17:06:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 17:06:11 volumio go-librespot[30501]: time="2026-01-13T17:06:11-06:00" level=debug msg="obtained new client token: AAAYSeTTP+G41ZzcIDCph4tAPh2hV9jQjPqK+bqk9NvRWtr5d1oWUgYEBxMd8KJu7dxoeyv0j8X3LbFfGtLmtPyt3yQNHdbd51b+ATBZa1v0QlPn/PEVhoC48Ylsui0JjCP8VJ+OSdoTSFlCyOZjwkReO8xgOOgCpGKmZCePkWwUsFXhpG4lVLRPLW/Nnnkzht5S/8Acp5EsKfB9A7TuVGys86x62VTmIpGhK82W66aLqEsfIKwOI9soCQ==" Jan 13 17:06:11 volumio volumio[30121]: info: MPD Permissions set Jan 13 17:06:11 volumio volumio[30121]: info: Shairport-Sync Started Jan 13 17:06:11 volumio volumio[30121]: Error adding Membership: Error: addMembership EINVAL Jan 13 17:06:11 volumio volumio[30121]: info: Shairport-Sync Started Jan 13 17:06:11 volumio volumio[30121]: info: Shairport-Sync Started Jan 13 17:06:11 volumio volumio[30121]: 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 17:06:11 volumio go-librespot[30501]: time="2026-01-13T17:06:11-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:12 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 17:06:12 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:12 volumio go-librespot[30501]: time="2026-01-13T17:06:12-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:12 volumio go-librespot[30501]: time="2026-01-13T17:06:12-06:00" level=debug msg="completed challenge" Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:12 volumio go-librespot[30501]: time="2026-01-13T17:06:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 17:06:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:12 volumio sudo[30558]: 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 17:06:12 volumio sudo[30558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:12 volumio sudo[30558]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::volumioGetState Jan 13 17:06:12 volumio volumio[30121]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:12 volumio volumio[30121]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 13 17:06:12 volumio volumio[30121]: info: Starting Shairport Sync Jan 13 17:06:12 volumio sudo[30567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 13 17:06:12 volumio sudo[30567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:12 volumio volumio[30121]: 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 17:06:12 volumio volumio[30121]: info: Spotify Successfully logged in Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:12 volumio volumio[30121]: info: [1768345572435] CoreMusicLibrary::Adding element Spotify Jan 13 17:06:12 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:12 volumio volumio[30121]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:12 volumio volumio[30121]: Cannot find translation for source SoundCloud Jan 13 17:06:12 volumio volumio[30121]: Cannot find translation for source YouTube2 Jan 13 17:06:12 volumio volumio[30121]: Cannot find translation for source YouTube Music Jan 13 17:06:12 volumio volumio[30121]: Cannot find translation for source Podcast Jan 13 17:06:12 volumio volumio[30121]: Cannot find translation for source Volusonic Jan 13 17:06:12 volumio volumio[30121]: Cannot find translation for source Spotify Jan 13 17:06:12 volumio systemd[1]: Reloading. Jan 13 17:06:12 volumio sudo[30559]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 17:06:12 volumio sudo[30559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 17:06:12 volumio sudo[30569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:06:12 volumio sudo[30559]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:12 volumio sudo[30569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:12 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.244.220 Jan 13 17:06:12 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:06:12 volumio avahi-daemon[664]: Registering new address record for 169.254.244.220 on eth0.IPv4. Jan 13 17:06:13 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:13 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:13 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:13 volumio volumio[30121]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:06:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.244.220 Jan 13 17:06:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.244.220 Jan 13 17:06:13 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.244.220 Jan 13 17:06:13 volumio avahi-daemon[664]: Withdrawing address record for 169.254.244.220 on eth0. Jan 13 17:06:13 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:06:13 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:06:14 volumio volumio[30121]: info: go-librespot daemon successfully initialized Jan 13 17:06:15 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 17:06:15 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 17:06:15 volumio sudo[30567]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:15 volumio volumio[30121]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:15 volumio sudo[30637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:15 volumio sudo[30637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 13 17:06:15 volumio sudo[30637]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:15 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:15 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:15 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:15 volumio volumio[30121]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 13 17:06:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:15 volumio sudo[30642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 13 17:06:15 volumio sudo[30642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:15 volumio go-librespot[30641]: go-librespot daemon starting... Jan 13 17:06:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 17:06:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 17:06:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:06:15 volumio systemd[1]: shairport-sync.service: Consumed 1.405s CPU time. Jan 13 17:06:15 volumio go-librespot[30644]: time="2026-01-13T17:06:15-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:15 volumio go-librespot[30644]: time="2026-01-13T17:06:15-06:00" level=debug msg="app state loaded" Jan 13 17:06:15 volumio go-librespot[30644]: time="2026-01-13T17:06:15-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:15 volumio go-librespot[30644]: time="2026-01-13T17:06:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:15 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:15 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:15 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:06:15 volumio sudo[30569]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:15 volumio volumio[30121]: info: Shairport-Sync Started Jan 13 17:06:15 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 13 17:06:16 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 13 17:06:16 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 13 17:06:16 volumio sudo[30642]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:16 volumio go-librespot[30644]: time="2026-01-13T17:06:16-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 17:06:16 volumio go-librespot[30644]: time="2026-01-13T17:06:16-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 17:06:16 volumio go-librespot[30644]: time="2026-01-13T17:06:16-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 17:06:16 volumio go-librespot[30644]: time="2026-01-13T17:06:16-06:00" level=info msg="zeroconf server listening on port 38799" Jan 13 17:06:16 volumio go-librespot[30644]: time="2026-01-13T17:06:16-06:00" level=debug msg="obtained new client token: AACl/UxjN3PHaSyl9VDK4/gQpO16PGtV/tSrt+Wtk93ngbTPQXWK/9MK/KxMzzH0RAaXIMt8GUmWISP0ZKZK5Jt0fE9p4YtW6y7VI2FTISkV+1b8vYU3CFrXL2f9e9aGZYS8KE3zGq0NWeAgVe4XyY4Y4lr9BotPQTDtmdMAMSEJRsjzV70bx8/8wnnf5DzOVcKEWvlBQd2vaN5k248x+DvuWA+hZKHKnH331eHHWx38xdJza9kxAci0bA==" Jan 13 17:06:16 volumio go-librespot[30644]: time="2026-01-13T17:06:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:16 volumio go-librespot[30644]: time="2026-01-13T17:06:16-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:16 volumio go-librespot[30644]: time="2026-01-13T17:06:16-06:00" level=debug msg="completed challenge" Jan 13 17:06:16 volumio go-librespot[30644]: time="2026-01-13T17:06: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 17:06:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:16 volumio volumio[30121]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:16 volumio sudo[30668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:16 volumio sudo[30668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:16 volumio sudo[30668]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:16 volumio volumio[30121]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 13 17:06:16 volumio sudo[30672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 13 17:06:16 volumio sudo[30672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:16 volumio sudo[30672]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:16 volumio volumio[30121]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 13 17:06:16 volumio sudo[30675]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 13 17:06:16 volumio sudo[30675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:17 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 13 17:06:17 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 13 17:06:17 volumio sudo[30675]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:17 volumio volumio[30121]: info: Initializing connection to go-librespot Websocket Jan 13 17:06:17 volumio volumio[30121]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 17:06:17 volumio volumio[30121]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:17 volumio sudo[30683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:17 volumio sudo[30683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:17 volumio sudo[30683]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:18 volumio volumio[30121]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:18 volumio sudo[30686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:18 volumio sudo[30686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:18 volumio sudo[30686]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:18 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 17:06:18 volumio mpd[30635]: 2026-01-13T17:06:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 13 17:06:18 volumio volumio[30121]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:18 volumio sudo[30690]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:18 volumio sudo[30690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:18 volumio sudo[30690]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:18 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 13 17:06:18 volumio sudo[30434]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:18 volumio sudo[30529]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:18 volumio sudo[30444]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:19 volumio volumio[30121]: error: MPD error: The expression evaluated to a falsy value: Jan 13 17:06:19 volumio volumio[30121]: assert.ok(self.idling) Jan 13 17:06:19 volumio volumio[30121]: error: The expression evaluated to a falsy value: Jan 13 17:06:19 volumio volumio[30121]: assert.ok(self.idling) Jan 13 17:06:19 volumio volumio[30121]: error: MPD error: The expression evaluated to a falsy value: Jan 13 17:06:19 volumio volumio[30121]: assert.ok(self.idling) Jan 13 17:06:19 volumio volumio[30121]: error: The expression evaluated to a falsy value: Jan 13 17:06:19 volumio volumio[30121]: assert.ok(self.idling) Jan 13 17:06:19 volumio volumio[30121]: info: MPD running with PID30635 Jan 13 17:06:19 volumio volumio[30121]: ,establishing connection Jan 13 17:06:19 volumio volumio[30121]: error: updateQueue error: null Jan 13 17:06:19 volumio volumio[30121]: error: updateQueue error: null Jan 13 17:06:19 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.174.239 Jan 13 17:06:19 volumio avahi-daemon[664]: Registering new address record for 169.254.174.239 on eth0.IPv4. Jan 13 17:06:19 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:06:19 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:19 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:19 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:19 volumio volumio[30121]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:19 volumio sudo[30714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:19 volumio sudo[30714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:19 volumio sudo[30714]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:19 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.174.239 Jan 13 17:06:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 13 17:06:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:19 volumio go-librespot[30716]: go-librespot daemon starting... Jan 13 17:06:19 volumio go-librespot[30717]: time="2026-01-13T17:06:19-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:19 volumio go-librespot[30717]: time="2026-01-13T17:06:19-06:00" level=debug msg="app state loaded" Jan 13 17:06:19 volumio go-librespot[30717]: time="2026-01-13T17:06:19-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:19 volumio go-librespot[30717]: time="2026-01-13T17:06:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:19 volumio volumio[30121]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:19 volumio sudo[30725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:19 volumio sudo[30725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06:20-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06:20-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 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06:20-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 17:06:20 volumio sudo[30725]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06:20-06:00" level=info msg="zeroconf server listening on port 35209" Jan 13 17:06:20 volumio volumio[30121]: info: Completed starting Core Plugins Jan 13 17:06:20 volumio volumio[30121]: info: ------------------------------------------- Jan 13 17:06:20 volumio volumio[30121]: info: ----- MyVolumio plugins startup ---- Jan 13 17:06:20 volumio volumio[30121]: info: ------------------------------------------- Jan 13 17:06:20 volumio volumio[30121]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 13 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06:20-06:00" level=debug msg="obtained new client token: AAAoDan8cKB1eqPXdmPORrMDPfCfFg7mohLl91TuDPMi3weI3eafuhP8tFxgC5WYFOoow0K9qay4316M3wiI7g9USzb0QGVqhGi/vGCw1TkAW7v9t9BXSE9ZfE/LGwiKi4JLQ0c4X3fgvXSiQaS/bInh/L9ZPZz3r+gMsqjVB5qC+Xg8/IX8q0mpdm+lw/u7tmRP9VKEWTqPehd9/D31/m/Kfb5D9dp/2AxsJv5pkoNzLg0MSzRyREI=" Jan 13 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06:20-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 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Jan 13 17:06:20 volumio volumio[30121]: info: Initializing connection to go-librespot Websocket Jan 13 17:06:20 volumio ntpd[872]: IO: Listen normally on 14732 eth0 169.254.174.239:123 Jan 13 17:06:20 volumio ntpd[872]: IO: new interface(s) found: waking up resolver Jan 13 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06:20-06:00" level=debug msg="new websocket client" Jan 13 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06:20-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06:20-06:00" level=debug msg="completed challenge" Jan 13 17:06:20 volumio volumio[30121]: info: Connection to go-librespot Websocket established Jan 13 17:06:20 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.174.239 Jan 13 17:06:20 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.174.239 Jan 13 17:06:20 volumio avahi-daemon[664]: Withdrawing address record for 169.254.174.239 on eth0. Jan 13 17:06:20 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:06:20 volumio go-librespot[30717]: time="2026-01-13T17:06: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 17:06:20 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:06:20 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:20 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:20 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:20 volumio volumio[30121]: info: Connection to go-librespot Websocket closed Jan 13 17:06:21 volumio sudo[30744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 17:06:21 volumio sudo[30744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:21 volumio sudo[30746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 17:06:21 volumio sudo[30746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:21 volumio sudo[30748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 17:06:21 volumio sudo[30748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:22 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 13 17:06:22 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 13 17:06:22 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 13 17:06:22 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 13 17:06:22 volumio sudo[30744]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:22 volumio mpd_monitor.sh[30752]: MPD Monitor Service: Starting MPD Monitor Service Jan 13 17:06:22 volumio sudo[30746]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:22 volumio sudo[30748]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:22 volumio volumio[30121]: info: Successfully started MPD Monitor Jan 13 17:06:22 volumio volumio[30121]: info: Successfully started MPD Monitor Jan 13 17:06:22 volumio volumio[30121]: info: Successfully started MPD Monitor Jan 13 17:06:22 volumio ntpd[872]: IO: Deleting interface #14732 eth0, 169.254.174.239#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Jan 13 17:06:23 volumio volumio[30121]: info: Getting Spotify volume Jan 13 17:06:23 volumio volumio[30121]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 17:06:23 volumio volumio[30121]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 17:06:23 volumio volumio[30121]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 13 17:06:23 volumio volumio[30121]: errno: -111, Jan 13 17:06:23 volumio volumio[30121]: code: 'ECONNREFUSED', Jan 13 17:06:23 volumio volumio[30121]: syscall: 'connect', Jan 13 17:06:23 volumio volumio[30121]: address: '127.0.0.1', Jan 13 17:06:23 volumio volumio[30121]: port: 9879, Jan 13 17:06:23 volumio volumio[30121]: response: undefined Jan 13 17:06:23 volumio volumio[30121]: } Jan 13 17:06:23 volumio volumio[30121]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 17:06:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 13 17:06:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:23 volumio go-librespot[30782]: go-librespot daemon starting... Jan 13 17:06:23 volumio go-librespot[30783]: time="2026-01-13T17:06:23-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:23 volumio go-librespot[30783]: time="2026-01-13T17:06:23-06:00" level=debug msg="app state loaded" Jan 13 17:06:23 volumio go-librespot[30783]: time="2026-01-13T17:06:23-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:23 volumio go-librespot[30783]: time="2026-01-13T17:06:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:24 volumio go-librespot[30783]: time="2026-01-13T17:06: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 17:06:24 volumio go-librespot[30783]: time="2026-01-13T17:06: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 17:06:24 volumio go-librespot[30783]: time="2026-01-13T17:06: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 17:06:24 volumio go-librespot[30783]: time="2026-01-13T17:06:24-06:00" level=info msg="zeroconf server listening on port 39107" Jan 13 17:06:24 volumio sudo[30793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-13 17:05' Jan 13 17:06:24 volumio sudo[30793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:24 volumio go-librespot[30783]: time="2026-01-13T17:06:24-06:00" level=debug msg="obtained new client token: AAC03qz4/VA/whuI3eC1E1mWR+dKrPoa9qzKnsd1dUDXxeLx5L/y9+wE8LJixXHt0jXnskiOWEjccMC+evrPKRqzmogzk23dEilsVwtQEFgf3f6TKQNFsO8AWIP37U6bF5ax+WWyZoHowaIMVHc23O5Jt2aAganj9VF3W/28LBvgIRcZTXVvkPI5ULFJCYapj/V+bZjJ1+c4j55CzYuMJiaODiy8SEjNVEq/PGvDbj37EGELITfXzLk=" Jan 13 17:06:24 volumio go-librespot[30783]: time="2026-01-13T17:06:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:24 volumio go-librespot[30783]: time="2026-01-13T17:06:24-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:24 volumio go-librespot[30783]: time="2026-01-13T17:06:24-06:00" level=debug msg="completed challenge" Jan 13 17:06:24 volumio go-librespot[30783]: time="2026-01-13T17:06: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 17:06:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:24 volumio sudo[30793]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:24 volumio volumio-remote-updater[14193]: [2026-01-13 17:06:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 13 17:06:24 volumio volumio-remote-updater[14193]: [2026-01-13 17:06:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 13 17:06:24 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:24 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 13 17:06:24 volumio systemd[1]: volumio.service: Consumed 44.294s CPU time. Jan 13 17:06:24 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 13 17:06:24 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 13 17:06:24 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 23330. Jan 13 17:06:24 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 13 17:06:24 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 13 17:06:24 volumio systemd[1]: volumio.service: Consumed 44.294s CPU time. Jan 13 17:06:24 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 13 17:06:24 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 13 17:06:25 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.13.163 Jan 13 17:06:25 volumio avahi-daemon[664]: Registering new address record for 169.254.13.163 on eth0.IPv4. Jan 13 17:06:25 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:06:25 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:25 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:25 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:26 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.13.163 Jan 13 17:06:26 volumio volumio[30805]: info: ------------------------------------------- Jan 13 17:06:26 volumio volumio[30805]: info: ----- Volumio3 ---- Jan 13 17:06:26 volumio volumio[30805]: info: ------------------------------------------- Jan 13 17:06:26 volumio volumio[30805]: info: ----- System startup ---- Jan 13 17:06:26 volumio volumio[30805]: info: ------------------------------------------- Jan 13 17:06:26 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.13.163 Jan 13 17:06:26 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.13.163 Jan 13 17:06:26 volumio avahi-daemon[664]: Withdrawing address record for 169.254.13.163 on eth0. Jan 13 17:06:26 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:06:26 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:26 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:26 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:26 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:06:27 volumio volumio[30805]: info: MYVOLUMIO Environment detected Jan 13 17:06:27 volumio volumio[30805]: info: Plugin folders cleanup Jan 13 17:06:27 volumio volumio[30805]: info: Scanning into folder /volumio/app/plugins/ Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category audio_interface Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category miscellanea Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category music_service Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category plugins.json Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category system_controller Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category user_interface Jan 13 17:06:27 volumio volumio[30805]: info: Scanning into folder /data/plugins/ Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category audio_interface Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category music_service Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category system_controller Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category system_hardware Jan 13 17:06:27 volumio volumio[30805]: info: Scanning category user_interface Jan 13 17:06:27 volumio volumio[30805]: info: Plugin folders cleanup completed Jan 13 17:06:27 volumio volumio[30805]: info: ------------------------------------------- Jan 13 17:06:27 volumio volumio[30805]: info: ----- Core plugins startup ---- Jan 13 17:06:27 volumio volumio[30805]: info: ------------------------------------------- Jan 13 17:06:27 volumio volumio[30805]: info: Loading plugins from folder /volumio/app/plugins/ Jan 13 17:06:27 volumio volumio[30805]: info: Adding plugin upnp to MyMusic Plugins Jan 13 17:06:27 volumio volumio[30805]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 13 17:06:27 volumio volumio[30805]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 13 17:06:27 volumio volumio[30805]: info: Loading plugins from folder /data/plugins/ Jan 13 17:06:27 volumio volumio[30805]: info: Loading plugin "system"... Jan 13 17:06:27 volumio volumio[30805]: info: Loading plugin "appearance"... Jan 13 17:06:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 13 17:06:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:27 volumio go-librespot[30864]: go-librespot daemon starting... Jan 13 17:06:27 volumio go-librespot[30865]: time="2026-01-13T17:06:27-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:27 volumio go-librespot[30865]: time="2026-01-13T17:06:27-06:00" level=debug msg="app state loaded" Jan 13 17:06:27 volumio go-librespot[30865]: time="2026-01-13T17:06:27-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:27 volumio go-librespot[30865]: time="2026-01-13T17:06:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:28 volumio go-librespot[30865]: time="2026-01-13T17:06:28-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 17:06:28 volumio go-librespot[30865]: time="2026-01-13T17:06:28-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 13 17:06:28 volumio go-librespot[30865]: time="2026-01-13T17:06:28-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 13 17:06:28 volumio go-librespot[30865]: time="2026-01-13T17:06:28-06:00" level=info msg="zeroconf server listening on port 45183" Jan 13 17:06:28 volumio go-librespot[30865]: time="2026-01-13T17:06:28-06:00" level=debug msg="obtained new client token: AAAkOZ8c5xcuLIM+nQap2HuwdxURaD7BkofHz6pk2hNSEM/OSEzbT7cqmoE/dMqHEiIihDWZyCccbOz8xGprbGrVe7jXpPv2sF+Qol3pg9VlaSLoetggZo8mS93mXIt7A1+atNUZgwFWudlxks4KWqL6gIycyei2Qsb4maRNkIeQZpCeMeNLEnQVncUxrm23WuMLlFGBoKrnuOH2mRVyctQoHm1rvSsvQyFrA7VEo6/wUypIRMzhOm4=" Jan 13 17:06:28 volumio go-librespot[30865]: time="2026-01-13T17:06:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:28 volumio go-librespot[30865]: time="2026-01-13T17:06:28-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:28 volumio go-librespot[30865]: time="2026-01-13T17:06:28-06:00" level=debug msg="completed challenge" Jan 13 17:06:28 volumio go-librespot[30865]: time="2026-01-13T17:06: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 17:06:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:28 volumio volumio[30805]: info: Loading plugin "network"... Jan 13 17:06:28 volumio volumio[30805]: info: Refreshing Cached IP Addresses Jan 13 17:06:28 volumio sudo[30874]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 17:06:28 volumio sudo[30874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:28 volumio sudo[30876]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 17:06:28 volumio sudo[30876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:28 volumio sudo[30874]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:28 volumio volumio[30805]: info: Loading plugin "services"... Jan 13 17:06:28 volumio volumio[30805]: info: Loading plugin "alsa_controller"... Jan 13 17:06:28 volumio sudo[30876]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:28 volumio sudo[30884]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 13 17:06:28 volumio sudo[30884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:28 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 17:06:28 volumio volumio[30805]: info: Loading plugin "wizard"... Jan 13 17:06:28 volumio volumio[30805]: info: Loading plugin "networkfs"... Jan 13 17:06:28 volumio volumio[30805]: info: Starting Udev Watcher for removable devices Jan 13 17:06:28 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 17:06:28 volumio volumio[30805]: info: Ignoring mount for partition: boot Jan 13 17:06:28 volumio volumio[30805]: info: Ignoring mount for partition: volumio Jan 13 17:06:28 volumio volumio[30805]: info: Ignoring mount for partition: volumio_data Jan 13 17:06:29 volumio volumio[30805]: info: Mounting Device Wikipedia Jan 13 17:06:29 volumio sudo[30914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 13 17:06:29 volumio sudo[30914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:29 volumio sudo[30914]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:29 volumio volumio[30805]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 13 17:06:29 volumio volumio[30805]: dmesg(1) may have more information after failed mount system call. Jan 13 17:06:29 volumio volumio[30805]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 13 17:06:29 volumio volumio[30805]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 13 17:06:29 volumio volumio[30805]: dmesg(1) may have more information after failed mount system call. Jan 13 17:06:29 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 17:06:29 volumio volumio[30805]: info: Loading plugin "volumio_command_line_client"... Jan 13 17:06:29 volumio volumio[30805]: info: Loading plugin "upnp"... Jan 13 17:06:29 volumio volumio[30805]: info: [1768345589149] Starting Upmpd Daemon Jan 13 17:06:29 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 17:06:29 volumio volumio[30805]: info: Loading plugin "my_music"... Jan 13 17:06:29 volumio volumio[30805]: info: Loading plugin "mpd"... Jan 13 17:06:29 volumio sudo[30884]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:29 volumio volumio-remote-updater[14193]: [2026-01-13 17:06:29] [connect] Successful connection Jan 13 17:06:29 volumio volumio[30805]: info: Loading plugin "upnp_browser"... Jan 13 17:06:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 13 17:06:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:31 volumio go-librespot[30916]: go-librespot daemon starting... Jan 13 17:06:31 volumio go-librespot[30917]: time="2026-01-13T17:06:31-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:31 volumio go-librespot[30917]: time="2026-01-13T17:06:31-06:00" level=debug msg="app state loaded" Jan 13 17:06:31 volumio go-librespot[30917]: time="2026-01-13T17:06:31-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:31 volumio go-librespot[30917]: time="2026-01-13T17:06:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:31 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.184.19 Jan 13 17:06:31 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:06:31 volumio avahi-daemon[664]: Registering new address record for 169.254.184.19 on eth0.IPv4. Jan 13 17:06:31 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:31 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:31 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:32 volumio go-librespot[30917]: time="2026-01-13T17:06:32-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 17:06:32 volumio go-librespot[30917]: time="2026-01-13T17:06:32-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 17:06:32 volumio go-librespot[30917]: time="2026-01-13T17:06:32-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 17:06:32 volumio go-librespot[30917]: time="2026-01-13T17:06:32-06:00" level=info msg="zeroconf server listening on port 39937" Jan 13 17:06:32 volumio go-librespot[30917]: time="2026-01-13T17:06:32-06:00" level=debug msg="obtained new client token: AAAXhC6ofVzcz8t0cYdDYPtU+n96tP3gnINgZBPLXLJlQ2c3uMVJV8rSm+2ABiLCNBffWxD7mkkTIYD/4T67sES4i45HkYmGRQtHxIDNDTCCClY/iCpzF26DahsyMzBHZjhgLxzGu6vS1e5SRmPEBfrbG8oRCVhZLPFgRHdcLegMQDKBo7UoECLPctPgQJackg3JZnC9Hflii85UmfW/2UkI1VJeL9jocxa2BYftLH7sQJp0fSsgmkU=" Jan 13 17:06:32 volumio go-librespot[30917]: time="2026-01-13T17:06:32-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:32 volumio go-librespot[30917]: time="2026-01-13T17:06:32-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 13 17:06:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:32 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.184.19 Jan 13 17:06:32 volumio volumio[30805]: info: Loading plugin "alarm-clock"... Jan 13 17:06:32 volumio volumio[30805]: info: Loading plugin "airplay_emulation"... Jan 13 17:06:32 volumio volumio[30805]: info: Starting Shairport Sync Jan 13 17:06:32 volumio volumio[30805]: info: Loading plugin "last_100"... Jan 13 17:06:32 volumio volumio[30805]: info: Loading plugin "webradio"... Jan 13 17:06:32 volumio volumio[30805]: info: Loading plugin "i2s_dacs"... Jan 13 17:06:32 volumio volumio[30805]: info: I2S DAC not set, start Auto-detection Jan 13 17:06:32 volumio volumio[30805]: info: Loading plugin "volumiodiscovery"... Jan 13 17:06:32 volumio volumio[30805]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 13 17:06:32 volumio volumio[30805]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 17:06:32 volumio volumio[30805]: *** WARNING *** For more information see Jan 13 17:06:32 volumio volumio[30805]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 13 17:06:32 volumio volumio[30805]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 17:06:32 volumio volumio[30805]: *** WARNING *** For more information see Jan 13 17:06:32 volumio node[30805]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 13 17:06:32 volumio node[30805]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 17:06:32 volumio node[30805]: *** WARNING *** For more information see Jan 13 17:06:32 volumio node[30805]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 13 17:06:32 volumio node[30805]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 17:06:32 volumio node[30805]: *** WARNING *** For more information see Jan 13 17:06:32 volumio volumio[30805]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 13 17:06:32 volumio volumio[30805]: info: Discovery: Started advertising with name: Volumio Jan 13 17:06:32 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 17:06:32 volumio volumio[30805]: info: Loading plugin "bandcamp"... Jan 13 17:06:32 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.184.19 Jan 13 17:06:32 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.184.19 Jan 13 17:06:32 volumio avahi-daemon[664]: Withdrawing address record for 169.254.184.19 on eth0. Jan 13 17:06:32 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:06:32 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:32 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:32 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:32 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:06:34 volumio volumio[30805]: info: Plugin calmradio is not enabled Jan 13 17:06:34 volumio volumio[30805]: info: Loading plugin "soundcloud"... Jan 13 17:06:34 volumio volumio[30805]: info: Loading plugin "spop"... Jan 13 17:06:35 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 17:06:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 13 17:06:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:35 volumio volumio[30805]: info: Loading plugin "squeezelite_mc"... Jan 13 17:06:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:35 volumio go-librespot[30959]: go-librespot daemon starting... Jan 13 17:06:35 volumio go-librespot[30960]: time="2026-01-13T17:06:35-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:35 volumio go-librespot[30960]: time="2026-01-13T17:06:35-06:00" level=debug msg="app state loaded" Jan 13 17:06:35 volumio go-librespot[30960]: time="2026-01-13T17:06:35-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:35 volumio go-librespot[30960]: time="2026-01-13T17:06:35-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:35 volumio go-librespot[30960]: time="2026-01-13T17:06:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 17:06:35 volumio go-librespot[30960]: time="2026-01-13T17:06:35-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 17:06:35 volumio go-librespot[30960]: time="2026-01-13T17:06:35-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 17:06:35 volumio go-librespot[30960]: time="2026-01-13T17:06:35-06:00" level=info msg="zeroconf server listening on port 36565" Jan 13 17:06:35 volumio go-librespot[30960]: time="2026-01-13T17:06:35-06:00" level=debug msg="obtained new client token: AAAG/6LPGJhaJCgkCNpXXJ3POSrKPgU+pO4UZCpHpupixLQ5RtjHB0ziyGmdz2cTjVI8pv95OusrL/PWygDFBIj89bTZOOL2XkZ7l5tlgYxguXVnWGLL0lJe50V62dAXY5nYbcJILj4eAUrZQ9cXSxqFk5LmJopCAyHxMAOhUGmDwVnrzPKC6QfEXqm9b4UDoaQWsg2ckb2T70IimhoXloDFqbT2JHGCFTNXR9UZYFCRnqFwNb/Tq3RlYg==" Jan 13 17:06:36 volumio go-librespot[30960]: time="2026-01-13T17:06:36-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:36 volumio go-librespot[30960]: time="2026-01-13T17:06:36-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:36 volumio go-librespot[30960]: time="2026-01-13T17:06:36-06:00" level=debug msg="completed challenge" Jan 13 17:06:36 volumio volumio[30805]: info: Loading plugin "youtube2"... Jan 13 17:06:36 volumio go-librespot[30960]: time="2026-01-13T17:06: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 17:06:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:36 volumio volumio[30805]: info: Loading plugin "ytcr"... Jan 13 17:06:37 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.32.85 Jan 13 17:06:37 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:06:37 volumio avahi-daemon[664]: Registering new address record for 169.254.32.85 on eth0.IPv4. Jan 13 17:06:37 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:37 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:37 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:38 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.32.85 Jan 13 17:06:38 volumio volumio[30805]: info: Loading plugin "ytmusic"... Jan 13 17:06:38 volumio volumio[30805]: info: Plugin now_playing is not enabled Jan 13 17:06:38 volumio volumio[30805]: info: Loading plugin "outputs"... Jan 13 17:06:38 volumio volumio[30805]: info: Loading plugin "albumart"... Jan 13 17:06:38 volumio volumio[30805]: info: Plugin example_plugin is not enabled Jan 13 17:06:38 volumio volumio[30805]: info: Loading plugin "inputs"... Jan 13 17:06:38 volumio volumio[30805]: info: Loading plugin "updater_comm"... Jan 13 17:06:38 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.32.85 Jan 13 17:06:38 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.32.85 Jan 13 17:06:38 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:06:38 volumio avahi-daemon[664]: Withdrawing address record for 169.254.32.85 on eth0. Jan 13 17:06:38 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:38 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:38 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:06:38 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:38 volumio volumio[30805]: info: Plugin mpdemulation is not enabled Jan 13 17:06:38 volumio volumio[30805]: info: Loading plugin "rest_api"... Jan 13 17:06:38 volumio volumio[30805]: info: Loading plugin "websocket"... Jan 13 17:06:38 volumio volumio[30805]: info: Starting Socket.io Server version 1.7.4 Jan 13 17:06:38 volumio volumio[30805]: info: Plugin fusiondsp is not enabled Jan 13 17:06:38 volumio volumio[30805]: info: Plugin mpdoutput is not enabled Jan 13 17:06:38 volumio volumio[30805]: info: Plugin RoonBridge is not enabled Jan 13 17:06:38 volumio volumio[30805]: info: Loading plugin "podcast"... Jan 13 17:06:39 volumio volumio[30805]: info: ControllerPodcast::constructor Jan 13 17:06:39 volumio volumio[30805]: info: Loading plugin "volusonic"... Jan 13 17:06:39 volumio volumio[30984]: Forking 3 albumart workers Jan 13 17:06:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 13 17:06:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:39 volumio go-librespot[31044]: go-librespot daemon starting... Jan 13 17:06:39 volumio go-librespot[31053]: time="2026-01-13T17:06:39-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:39 volumio go-librespot[31053]: time="2026-01-13T17:06:39-06:00" level=debug msg="app state loaded" Jan 13 17:06:39 volumio go-librespot[31053]: time="2026-01-13T17:06:39-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:39 volumio go-librespot[31053]: time="2026-01-13T17:06:39-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:39 volumio go-librespot[31053]: time="2026-01-13T17:06:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 17:06:39 volumio go-librespot[31053]: time="2026-01-13T17:06:39-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 13 17:06:39 volumio go-librespot[31053]: time="2026-01-13T17:06:39-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 13 17:06:39 volumio go-librespot[31053]: time="2026-01-13T17:06:39-06:00" level=info msg="zeroconf server listening on port 42365" Jan 13 17:06:40 volumio go-librespot[31053]: time="2026-01-13T17:06:40-06:00" level=debug msg="obtained new client token: AABQg1rubhDRU67kbqOOFJxlkPHgcA+7mfg1JX6d7lvUlEiMkejl59bBP9Afn7V6daMPVnGbXcRoJpNct7vuaODotapXINlzxK/vdCayTi/WNz+NOYdfx+zC+pvYvjSXBqIRwldgTADfiqX2ncb4E6eY9QeFd2g8vZ0iHkaTceHse1U0O3azXApVOaYp9upxUtkhZ4XCJlqCdAKP7Sqmpv6/Ek0yrZ6yUGdg+JyPIpycjkLR9/CqC5TDgA==" Jan 13 17:06:40 volumio go-librespot[31053]: time="2026-01-13T17:06:40-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:40 volumio go-librespot[31053]: time="2026-01-13T17:06:40-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:40 volumio go-librespot[31053]: time="2026-01-13T17:06:40-06:00" level=debug msg="completed challenge" Jan 13 17:06:40 volumio go-librespot[31053]: time="2026-01-13T17:06: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 17:06:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:41 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 17:06:41 volumio volumio[30805]: info: Applying required configuration parameters for plugin volusonic Jan 13 17:06:41 volumio volumio[30805]: info: Loading plugin "backup_restore"... Jan 13 17:06:41 volumio volumio[31025]: Starting albumart workers Jan 13 17:06:41 volumio volumio[31027]: Starting albumart workers Jan 13 17:06:41 volumio volumio[31026]: Starting albumart workers Jan 13 17:06:42 volumio volumio[30805]: info: Applying required configuration parameters for plugin backup_restore Jan 13 17:06:42 volumio volumio[30805]: info: Plugin rpi_eeprom_config is not enabled Jan 13 17:06:42 volumio volumio[30805]: info: Plugin rpi_eeprom_updater is not enabled Jan 13 17:06:42 volumio volumio[30805]: info: Loading plugin "scheduledrestart"... Jan 13 17:06:42 volumio volumio-remote-updater[14193]: [2026-01-13 17:06:42] [connect] Successful connection Jan 13 17:06:42 volumio volumio[30805]: info: Applying required configuration parameters for plugin scheduledrestart Jan 13 17:06:42 volumio volumio[30805]: info: Plugin Bluetoothremote is not enabled Jan 13 17:06:42 volumio volumio[30805]: info: Plugin music_services_shield is not enabled Jan 13 17:06:42 volumio volumio[30805]: info: Loading plugin "Systeminfo"... Jan 13 17:06:43 volumio volumio[30805]: info: Plugin peppymeterbasic is not enabled Jan 13 17:06:43 volumio volumio[30805]: info: Loading plugin "peppyspectrum"... Jan 13 17:06:43 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.93.3 Jan 13 17:06:43 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:06:43 volumio avahi-daemon[664]: Registering new address record for 169.254.93.3 on eth0.IPv4. Jan 13 17:06:43 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:43 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:43 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:43 volumio volumio[30805]: info: Loading i18n strings for locale en Jan 13 17:06:43 volumio volumio[30805]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 17:06:43 volumio volumio[30805]: Updating browse sources language Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 13 17:06:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:43 volumio go-librespot[31102]: go-librespot daemon starting... Jan 13 17:06:43 volumio go-librespot[31103]: time="2026-01-13T17:06:43-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:43 volumio go-librespot[31103]: time="2026-01-13T17:06:43-06:00" level=debug msg="app state loaded" Jan 13 17:06:43 volumio go-librespot[31103]: time="2026-01-13T17:06:43-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:43 volumio go-librespot[31103]: time="2026-01-13T17:06:43-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::initPlayerControls Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:06:43 volumio volumio[30805]: Express server listening on port 3000 Jan 13 17:06:43 volumio volumio[30805]: [Metrics] WebUI: 17s 689.45ms Jan 13 17:06:43 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.93.3 Jan 13 17:06:43 volumio volumio[30805]: info: CoreStateMachine::resetVolumioState Jan 13 17:06:43 volumio volumio[30805]: info: CoreStateMachine::getcurrentVolume Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 17:06:43 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:43 volumio sudo[31115]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 17:06:43 volumio sudo[31115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:43 volumio sudo[31117]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 17:06:43 volumio sudo[31117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:43 volumio sudo[31117]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:43 volumio sudo[31115]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:43 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.93.3 Jan 13 17:06:44 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.93.3 Jan 13 17:06:44 volumio avahi-daemon[664]: Withdrawing address record for 169.254.93.3 on eth0. Jan 13 17:06:44 volumio volumio[30805]: info: Volumio Network Manager: Network status updated: 1 Jan 13 17:06:44 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:06:44 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:44 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:44 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:44 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:06:44 volumio volumio[30805]: info: VolumeController:: Volume=100 Mute =false Jan 13 17:06:44 volumio volumio[30805]: info: CoreStateMachine::pushState Jan 13 17:06:44 volumio volumio[30805]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioPushState Jan 13 17:06:44 volumio volumio[30805]: info: CoreStateMachine::updateTrackBlock Jan 13 17:06:44 volumio volumio[30805]: info: CorePlayQueue::getTrackBlock Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 17:06:44 volumio go-librespot[31103]: time="2026-01-13T17:06: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 17:06:44 volumio go-librespot[31103]: time="2026-01-13T17:06:44-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 17:06:44 volumio go-librespot[31103]: time="2026-01-13T17:06:44-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 17:06:44 volumio volumio-remote-updater[14193]: [2026-01-13 17:06:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768345602 101 Jan 13 17:06:44 volumio go-librespot[31103]: time="2026-01-13T17:06:44-06:00" level=info msg="zeroconf server listening on port 34609" Jan 13 17:06:44 volumio volumio[30805]: 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 17:06:44 volumio volumio[30805]: info: Reloading queue from file Jan 13 17:06:44 volumio volumio[30805]: info: CoreStateMachine::setRepeat null single undefined Jan 13 17:06:44 volumio volumio[30805]: info: CoreStateMachine::pushState Jan 13 17:06:44 volumio volumio[30805]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioPushState Jan 13 17:06:44 volumio volumio[30805]: info: CoreStateMachine::setRandom null Jan 13 17:06:44 volumio volumio[30805]: info: CoreStateMachine::pushState Jan 13 17:06:44 volumio volumio[30805]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioPushState Jan 13 17:06:44 volumio volumio[30805]: info: Setting Device type: Raspberry PI Jan 13 17:06:44 volumio volumio[30805]: info: VolumeController:: Volume=100 Mute =false Jan 13 17:06:44 volumio volumio[30805]: info: CoreStateMachine::pushState Jan 13 17:06:44 volumio volumio[30805]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioPushState Jan 13 17:06:44 volumio volumio[30805]: info: Completed loading Core Plugins Jan 13 17:06:44 volumio volumio[30805]: info: Preparing to generate the ALSA configuration file Jan 13 17:06:44 volumio go-librespot[31103]: time="2026-01-13T17:06:44-06:00" level=debug msg="obtained new client token: AAC3jJCNgUH22NCCY+iPer8vhBC42MJ6MJD0uvVmbRmwamX/CTmUg9XvYuHU0ylfZqsNDEiDNf7RxSyFPDMENnCqCyMnPBE44OFZvpb09yRbxWxxqywlw/vt7qDOkW5fQZUftqLbA9GPB2RnS9ED9tIE9eeMydfbZjfhVfc94yfzZyQA2XF9Mbq0GxQZNKyokWGOV4ReK7vzirUUBzjd2VVGp3jAvcFq0uYRmTRR7l0Hxh0BK1VlaRK+WQ==" Jan 13 17:06:44 volumio sudo[31147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 13 17:06:44 volumio sudo[31147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:44 volumio volumio[30805]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 17:06:44 volumio volumio[30805]: info: Discovery: Found device Volumio Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioGetState Jan 13 17:06:44 volumio volumio[30805]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:44 volumio volumio[30805]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 17:06:44 volumio volumio[30805]: info: Reading ALSA contributions from plugins. Jan 13 17:06:44 volumio sudo[31147]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:44 volumio volumio[30805]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 17:06:44 volumio volumio[30805]: info: Discovery: Found device Volumio Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioGetState Jan 13 17:06:44 volumio volumio[30805]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:44 volumio volumio[30805]: info: Upmpdcli Daemon Started Jan 13 17:06:44 volumio volumio[30805]: info: Asound.conf file unchanged, so no further update is needed Jan 13 17:06:44 volumio volumio[30805]: info: Output device has changed, restarting MPD Jan 13 17:06:44 volumio go-librespot[31103]: time="2026-01-13T17:06:44-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:44 volumio volumio[30805]: info: Output device has changed, restarting Shairport Sync Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:44 volumio sudo[31150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 17:06:44 volumio sudo[31150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:44 volumio sudo[31152]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 17:06:44 volumio sudo[31152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:44 volumio sudo[31150]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:44 volumio volumio[30805]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:06:44 volumio volumio[30805]: info: ___________ START PLUGINS ___________ Jan 13 17:06:44 volumio go-librespot[31103]: time="2026-01-13T17:06:44-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:44 volumio volumio[30805]: info: ControllerMpd::onStart: Initializing MPD Jan 13 17:06:44 volumio go-librespot[31103]: time="2026-01-13T17:06:44-06:00" level=debug msg="completed challenge" Jan 13 17:06:44 volumio volumio[30805]: info: Creating MPD Configuration file Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:44 volumio volumio[30805]: info: [1768345604515] CoreMusicLibrary::Adding element Media Servers Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:44 volumio sudo[31160]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 17:06:44 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 13 17:06:44 volumio go-librespot[31103]: time="2026-01-13T17:06: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 17:06:44 volumio sudo[31160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:44 volumio sudo[31162]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 17:06:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:44 volumio sudo[31162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:44 volumio sudo[31160]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:44 volumio volumio[30805]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:44 volumio volumio[30805]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:44 volumio volumio[30805]: info: [1768345604644] CoreMusicLibrary::Adding element Last_100 Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:44 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 17:06:44 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 17:06:44 volumio systemd[1]: mpd.service: Consumed 3.811s CPU time. Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:44 volumio volumio[30805]: info: [1768345604649] CoreMusicLibrary::Adding element Webradio Jan 13 17:06:44 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:44 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 17:06:44 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 17:06:44 volumio volumio[30805]: info: Initializing BBC Radios Jan 13 17:06:44 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 17:06:44 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:44 volumio volumio[30805]: info: [1768345604735] CoreMusicLibrary::Adding element Bandcamp Discover Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:44 volumio volumio[30805]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:44 volumio volumio[30805]: info: [1768345604746] CoreMusicLibrary::Adding element SoundCloud Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:44 volumio volumio[30805]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:44 volumio volumio[30805]: Cannot find translation for source SoundCloud Jan 13 17:06:44 volumio volumio[30805]: info: Creating Spotify config file Jan 13 17:06:44 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:44 volumio sudo[31187]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 17:06:44 volumio sudo[31187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 17:06:44 volumio sudo[31187]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:45 volumio volumio[30805]: info: [squeezelite_mc] Starting proxy server... Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:45 volumio volumio[30805]: info: [1768345605111] CoreMusicLibrary::Adding element YouTube2 Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source SoundCloud Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube2 Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:45 volumio volumio[30805]: info: [1768345605130] CoreMusicLibrary::Adding element YouTube Music Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source SoundCloud Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube2 Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube Music Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:45 volumio volumio[30805]: info: [1768345605141] CoreMusicLibrary::Adding element Podcast Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source SoundCloud Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube2 Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube Music Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Podcast Jan 13 17:06:45 volumio volumio[30805]: info: Loading i18n strings for locale en Jan 13 17:06:45 volumio volumio[30805]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 17:06:45 volumio volumio[30805]: Updating browse sources language Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source SoundCloud Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube2 Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube Music Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Podcast Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source SoundCloud Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube2 Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube Music Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Podcast Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:45 volumio volumio[30805]: info: [1768345605189] CoreMusicLibrary::Adding element Volusonic Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source SoundCloud Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube2 Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source YouTube Music Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Podcast Jan 13 17:06:45 volumio volumio[30805]: Cannot find translation for source Volusonic Jan 13 17:06:45 volumio volumio[30805]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 13 17:06:45 volumio volumio[30805]: info: Volumio Calling Home Jan 13 17:06:45 volumio volumio[30805]: info: [squeezelite_mc] Proxy server started on port 35749 Jan 13 17:06:45 volumio volumio[30805]: info: Preparing to generate the ALSA configuration file Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 17:06:45 volumio volumio[30805]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 17:06:45 volumio volumio[30805]: info: Reading ALSA contributions from plugins. Jan 13 17:06:45 volumio volumio[30805]: info: MPD Permissions set Jan 13 17:06:45 volumio volumio[30805]: info: MPD Permissions set Jan 13 17:06:45 volumio volumio[30805]: info: Spotify config file written Jan 13 17:06:45 volumio sudo[31199]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 13 17:06:45 volumio sudo[31199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:45 volumio volumio[30805]: 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 17:06:45 volumio volumio[30805]: info: VolumeController:: Volume=100 Mute =false Jan 13 17:06:45 volumio volumio[30805]: info: CoreStateMachine::pushState Jan 13 17:06:45 volumio volumio[30805]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::volumioPushState Jan 13 17:06:45 volumio volumio[30805]: info: [squeezelite_mc] Server discovery started Jan 13 17:06:45 volumio volumio[30805]: info: [squeezelite_mc] Player finder started Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 13 17:06:45 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 17:06:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:45 volumio go-librespot[31205]: go-librespot daemon starting... Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:45 volumio volumio[30805]: info: No need to fix Spotify hosts Jan 13 17:06:45 volumio sudo[31199]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:45 volumio go-librespot[31215]: time="2026-01-13T17:06:45-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:45 volumio go-librespot[31215]: time="2026-01-13T17:06:45-06:00" level=debug msg="app state loaded" Jan 13 17:06:45 volumio go-librespot[31215]: time="2026-01-13T17:06:45-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:45 volumio go-librespot[31215]: time="2026-01-13T17:06:45-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:45 volumio volumio[30805]: 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 17:06:45 volumio volumio[30805]: info: Volumio called home Jan 13 17:06:45 volumio volumio[30805]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 13 17:06:45 volumio volumio[30805]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 13 17:06:46 volumio volumio[30805]: 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 17:06:46 volumio volumio[30805]: info: Starting Shairport Sync Jan 13 17:06:46 volumio go-librespot[31215]: time="2026-01-13T17:06:46-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 17:06:46 volumio go-librespot[31215]: time="2026-01-13T17:06:46-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 17:06:46 volumio go-librespot[31215]: time="2026-01-13T17:06:46-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 17:06:46 volumio volumio[30805]: info: Starting Shairport Sync Jan 13 17:06:46 volumio go-librespot[31215]: time="2026-01-13T17:06:46-06:00" level=info msg="zeroconf server listening on port 33729" Jan 13 17:06:46 volumio volumio[30805]: info: Starting Shairport Sync Jan 13 17:06:46 volumio volumio[30805]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 17:06:46 volumio volumio[30805]: SPOTIFY: BQCIeieUh91Z1y4psEEY0Dmh-zH6TrgD5nTEbb3_Plp0_oVC4ilE45rATmgIL09OXp4kNiZYh-W6kGlMXdcC0rk6D5fpYIlkF0g7J79y6639EQyH3VOccWk4bJiMNAMVSidjW1SKjI_N2ihpgvhTFan3RvVAMs4yJmhkGX5tQ2XuNzt6A1leEaaP3cTGISY-oaZbBUG3gK8PqszNA7b6XGpUdnrC4k44DPPtwFg Jan 13 17:06:46 volumio sudo[31227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:06:46 volumio sudo[31227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:46 volumio volumio[30805]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 17:06:46 volumio volumio[30805]: info: New Spotify access token = BQCIeieUh91Z1y4psEEY0Dmh-zH6TrgD5nTEbb3_Plp0_oVC4ilE45rATmgIL09OXp4kNiZYh-W6kGlMXdcC0rk6D5fpYIlkF0g7J79y6639EQyH3VOccWk4bJiMNAMVSidjW1SKjI_N2ihpgvhTFan3RvVAMs4yJmhkGX5tQ2XuNzt6A1leEaaP3cTGISY-oaZbBUG3gK8PqszNA7b6XGpUdnrC4k44DPPtwFg Jan 13 17:06:46 volumio volumio[30805]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 13 17:06:46 volumio sudo[31230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:06:46 volumio sudo[31230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:46 volumio sudo[31228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:06:46 volumio sudo[31228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:46 volumio sudo[31224]: 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 17:06:46 volumio sudo[31224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:46 volumio sudo[31224]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:46 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 17:06:46 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 17:06:46 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:06:46 volumio systemd[1]: shairport-sync.service: Consumed 1.972s CPU time. Jan 13 17:06:46 volumio go-librespot[31215]: time="2026-01-13T17:06:46-06:00" level=debug msg="obtained new client token: AADOW/lmOpUaa5Aaz09ML0DrZALw0A+bVkAGvPLTlWXXQy+9O/tGoM4Pcx9fc8FSiS+t32pIIQYf/aVx/8Mx9LLikSeZ8/jNztRrJJQ0SSqeyAyeY6EZJv7V1Epa2zSnM49KL4Ta94zO7DSOcfDAwK0JV/f/VggYvSm19nFHuUq7Nte1Xur9d5G9i0RPTrcEjVaDmZBuZA6kE5aSpFGXusydCp9SN5B+G7gOlELSTEj0SbrktwfY6dM=" Jan 13 17:06:46 volumio go-librespot[31215]: time="2026-01-13T17:06:46-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:06:46 volumio sudo[31227]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:46 volumio sudo[31230]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:46 volumio volumio[30805]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 13 17:06:46 volumio volumio[30805]: info: Asound.conf file unchanged, so no further update is needed Jan 13 17:06:46 volumio volumio[30805]: info: Output device has changed, restarting MPD Jan 13 17:06:46 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 17:06:46 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 17:06:46 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:06:46 volumio volumio[30805]: info: Output device has changed, restarting Shairport Sync Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:46 volumio go-librespot[31215]: time="2026-01-13T17:06:46-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:46 volumio go-librespot[31215]: time="2026-01-13T17:06:46-06:00" level=debug msg="completed challenge" Jan 13 17:06:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:06:46 volumio sudo[31228]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:46 volumio sudo[31242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 17:06:46 volumio sudo[31242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:46 volumio sudo[31242]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:46 volumio sudo[31239]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 13 17:06:46 volumio go-librespot[31215]: time="2026-01-13T17:06:46-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 17:06:46 volumio sudo[31239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:46 volumio volumio[30805]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:06:46 volumio sudo[31239]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:46 volumio sudo[31243]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 17:06:46 volumio sudo[31243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:46 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 17:06:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 17:06:46 volumio systemd[1]: mpd.service: Consumed 1.731s CPU time. Jan 13 17:06:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 17:06:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 17:06:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 17:06:46 volumio volumio[30805]: info: Shairport-Sync Started Jan 13 17:06:46 volumio volumio[30805]: Error adding Membership: Error: addMembership EINVAL Jan 13 17:06:46 volumio volumio[30805]: info: MPD Permissions set Jan 13 17:06:46 volumio volumio[30805]: 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 17:06:46 volumio volumio[30805]: info: Shairport-Sync Started Jan 13 17:06:46 volumio volumio[30805]: info: Shairport-Sync Started Jan 13 17:06:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 17:06:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:46 volumio sudo[31272]: 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 17:06:46 volumio sudo[31272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:46 volumio sudo[31272]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:46 volumio volumio[30805]: info: CoreCommandRouter::volumioGetState Jan 13 17:06:46 volumio volumio[30805]: info: CorePlayQueue::getTrack 0 Jan 13 17:06:47 volumio volumio[30805]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 13 17:06:47 volumio volumio[30805]: info: Starting Shairport Sync Jan 13 17:06:47 volumio sudo[31281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 13 17:06:47 volumio sudo[31281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:47 volumio sudo[31283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:06:47 volumio sudo[31283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:47 volumio volumio[30805]: 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 17:06:47 volumio volumio[30805]: info: Spotify Successfully logged in Jan 13 17:06:47 volumio systemd[1]: Reloading. Jan 13 17:06:47 volumio volumio[30805]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:06:47 volumio volumio[30805]: info: [1768345607254] CoreMusicLibrary::Adding element Spotify Jan 13 17:06:47 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:06:47 volumio volumio[30805]: Cannot find translation for source Bandcamp Discover Jan 13 17:06:47 volumio volumio[30805]: Cannot find translation for source SoundCloud Jan 13 17:06:47 volumio volumio[30805]: Cannot find translation for source YouTube2 Jan 13 17:06:47 volumio volumio[30805]: Cannot find translation for source YouTube Music Jan 13 17:06:47 volumio volumio[30805]: Cannot find translation for source Podcast Jan 13 17:06:47 volumio volumio[30805]: Cannot find translation for source Volusonic Jan 13 17:06:47 volumio volumio[30805]: Cannot find translation for source Spotify Jan 13 17:06:47 volumio sudo[31273]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 17:06:47 volumio sudo[31273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 17:06:47 volumio sudo[31273]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:47 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 17:06:48 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:48 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:48 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:06:48 volumio volumio[30805]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:06:48 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.36.230 Jan 13 17:06:48 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:06:48 volumio avahi-daemon[664]: Registering new address record for 169.254.36.230 on eth0.IPv4. Jan 13 17:06:48 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.36.230 Jan 13 17:06:48 volumio volumio[30805]: info: go-librespot daemon successfully initialized Jan 13 17:06:49 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.36.230 Jan 13 17:06:49 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.36.230 Jan 13 17:06:49 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:06:49 volumio avahi-daemon[664]: Withdrawing address record for 169.254.36.230 on eth0. Jan 13 17:06:49 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:06:49 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 17:06:49 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 17:06:50 volumio sudo[31281]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:50 volumio volumio[30805]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:50 volumio sudo[31353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:50 volumio sudo[31353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 13 17:06:50 volumio sudo[31353]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:50 volumio volumio[30805]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 13 17:06:50 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:50 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:50 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:50 volumio sudo[31357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 13 17:06:50 volumio sudo[31357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:50 volumio go-librespot[31358]: go-librespot daemon starting... Jan 13 17:06:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 17:06:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 17:06:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:06:50 volumio systemd[1]: shairport-sync.service: Consumed 1.536s CPU time. Jan 13 17:06:50 volumio go-librespot[31360]: time="2026-01-13T17:06:50-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:50 volumio go-librespot[31360]: time="2026-01-13T17:06:50-06:00" level=debug msg="app state loaded" Jan 13 17:06:50 volumio go-librespot[31360]: time="2026-01-13T17:06:50-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:50 volumio go-librespot[31360]: time="2026-01-13T17:06:50-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:06:50 volumio sudo[31283]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:50 volumio volumio[30805]: info: Shairport-Sync Started Jan 13 17:06:50 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:50 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:50 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:50 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 13 17:06:50 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 13 17:06:50 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 13 17:06:50 volumio sudo[31357]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:50 volumio go-librespot[31360]: time="2026-01-13T17:06:50-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 17:06:50 volumio go-librespot[31360]: time="2026-01-13T17:06:50-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 17:06:50 volumio go-librespot[31360]: time="2026-01-13T17:06:50-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 17:06:50 volumio go-librespot[31360]: time="2026-01-13T17:06:50-06:00" level=info msg="zeroconf server listening on port 33989" Jan 13 17:06:51 volumio go-librespot[31360]: time="2026-01-13T17:06:51-06:00" level=debug msg="obtained new client token: AACo0gMNY5r1PFsBdhhhEy7j6kszaBmI+GOzm1zh5F/hNajGEYUAwgJ9VbdvGFDHqwr6dm6au2XB6vcEh3EyStO60kVdAtaHYX+LdpHHbjy6XXQohf/B35apF6CPadH7znOyWI3+DEbOgFwCOhsrYqbf+uWgs+PdNttIm4rXU4q7baq1eJWhNdebn5JgGQPlqANpiBvnml8/UUDyFhpSgmqtSOOW/akzYCUAdoh+wskn0LdLgo0fyrw=" Jan 13 17:06:51 volumio go-librespot[31360]: time="2026-01-13T17:06:51-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:51 volumio go-librespot[31360]: time="2026-01-13T17:06:51-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:51 volumio go-librespot[31360]: time="2026-01-13T17:06:51-06:00" level=debug msg="completed challenge" Jan 13 17:06:51 volumio go-librespot[31360]: time="2026-01-13T17:06:51-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 17:06:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:51 volumio volumio[30805]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:51 volumio sudo[31385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:51 volumio sudo[31385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:51 volumio sudo[31385]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:51 volumio volumio[30805]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 13 17:06:51 volumio sudo[31389]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 13 17:06:51 volumio sudo[31389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:51 volumio sudo[31389]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:51 volumio volumio[30805]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 13 17:06:51 volumio sudo[31392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 13 17:06:51 volumio sudo[31392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:51 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 13 17:06:51 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 13 17:06:51 volumio sudo[31392]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:51 volumio volumio[30805]: info: Initializing connection to go-librespot Websocket Jan 13 17:06:52 volumio volumio[30805]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 17:06:52 volumio volumio[30805]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:52 volumio sudo[31399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:52 volumio sudo[31399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:52 volumio sudo[31399]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:52 volumio volumio[30805]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:52 volumio sudo[31402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:52 volumio sudo[31402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:53 volumio sudo[31402]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:53 volumio mpd[31351]: 2026-01-13T17:06:53 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 13 17:06:53 volumio volumio[30805]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:53 volumio sudo[31405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:53 volumio sudo[31405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:53 volumio sudo[31405]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:53 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 13 17:06:53 volumio sudo[31152]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:53 volumio sudo[31243]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:53 volumio sudo[31162]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:53 volumio volumio[30805]: error: MPD error: The expression evaluated to a falsy value: Jan 13 17:06:53 volumio volumio[30805]: assert.ok(self.idling) Jan 13 17:06:53 volumio volumio[30805]: error: The expression evaluated to a falsy value: Jan 13 17:06:53 volumio volumio[30805]: assert.ok(self.idling) Jan 13 17:06:53 volumio volumio[30805]: error: MPD error: The expression evaluated to a falsy value: Jan 13 17:06:53 volumio volumio[30805]: assert.ok(self.idling) Jan 13 17:06:53 volumio volumio[30805]: error: The expression evaluated to a falsy value: Jan 13 17:06:53 volumio volumio[30805]: assert.ok(self.idling) Jan 13 17:06:53 volumio volumio[30805]: info: MPD running with PID31351 Jan 13 17:06:53 volumio volumio[30805]: ,establishing connection Jan 13 17:06:53 volumio volumio[30805]: error: updateQueue error: null Jan 13 17:06:53 volumio volumio[30805]: error: updateQueue error: null Jan 13 17:06:53 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 17:06:54 volumio volumio[30805]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:54 volumio sudo[31413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:54 volumio sudo[31413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:54 volumio sudo[31413]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 13 17:06:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:54 volumio go-librespot[31415]: go-librespot daemon starting... Jan 13 17:06:54 volumio go-librespot[31416]: time="2026-01-13T17:06:54-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:54 volumio go-librespot[31416]: time="2026-01-13T17:06:54-06:00" level=debug msg="app state loaded" Jan 13 17:06:54 volumio go-librespot[31416]: time="2026-01-13T17:06:54-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:54 volumio go-librespot[31416]: time="2026-01-13T17:06:54-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:54 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.231.168 Jan 13 17:06:54 volumio avahi-daemon[664]: Registering new address record for 169.254.231.168 on eth0.IPv4. Jan 13 17:06:54 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:06:54 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:54 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:54 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:54 volumio volumio[30805]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 13 17:06:54 volumio sudo[31441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 13 17:06:54 volumio sudo[31441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:54 volumio sudo[31441]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:54 volumio volumio[30805]: info: Completed starting Core Plugins Jan 13 17:06:54 volumio volumio[30805]: info: ------------------------------------------- Jan 13 17:06:54 volumio volumio[30805]: info: ----- MyVolumio plugins startup ---- Jan 13 17:06:54 volumio volumio[30805]: info: ------------------------------------------- Jan 13 17:06:54 volumio volumio[30805]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 13 17:06:54 volumio go-librespot[31416]: time="2026-01-13T17:06:54-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 17:06:54 volumio go-librespot[31416]: time="2026-01-13T17:06:54-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 17:06:54 volumio go-librespot[31416]: time="2026-01-13T17:06:54-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 17:06:54 volumio go-librespot[31416]: time="2026-01-13T17:06:54-06:00" level=info msg="zeroconf server listening on port 46863" Jan 13 17:06:54 volumio go-librespot[31416]: time="2026-01-13T17:06:54-06:00" level=debug msg="obtained new client token: AAAWIoIczcY4AUP+XhnETM/QR+FyXJHSkpKy97q4nb5kT0YDLDiLN8jYSLw9wq47pGhH96s4fd96XQeAjOE7bF/IAn92PHlb9KlFlU3wZTmGE7F+/IbVpRCdbJ3OxL3A6Gw0kIvyIs+ohRBfT/GhkxbuaCOyEI+sRDzbcz/o8rvOWD0uIKsB7MJBKbGXOUPJ6SxC3xWYNu8xSKSrSHmDgWliAFGkHi7RA848rOIBUcPy1NS+7CIG8/hfQg==" Jan 13 17:06:55 volumio volumio[30805]: info: Initializing connection to go-librespot Websocket Jan 13 17:06:55 volumio go-librespot[31416]: time="2026-01-13T17:06:55-06:00" level=debug msg="new websocket client" Jan 13 17:06:55 volumio volumio[30805]: info: Connection to go-librespot Websocket established Jan 13 17:06:55 volumio go-librespot[31416]: time="2026-01-13T17:06:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:55 volumio go-librespot[31416]: time="2026-01-13T17:06:55-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:55 volumio go-librespot[31416]: time="2026-01-13T17:06:55-06:00" level=debug msg="completed challenge" Jan 13 17:06:55 volumio go-librespot[31416]: time="2026-01-13T17:06:55-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 17:06:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:55 volumio volumio[30805]: info: Connection to go-librespot Websocket closed Jan 13 17:06:55 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.231.168 Jan 13 17:06:55 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.231.168 Jan 13 17:06:55 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.231.168 Jan 13 17:06:55 volumio avahi-daemon[664]: Withdrawing address record for 169.254.231.168 on eth0. Jan 13 17:06:55 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:06:55 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:06:55 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:55 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:06:55 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:06:56 volumio sudo[31461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 17:06:56 volumio sudo[31461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:56 volumio sudo[31463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 17:06:56 volumio sudo[31463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:56 volumio sudo[31465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 13 17:06:56 volumio sudo[31465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:56 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 13 17:06:56 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 13 17:06:56 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 13 17:06:56 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 13 17:06:56 volumio sudo[31465]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:56 volumio mpd_monitor.sh[31469]: MPD Monitor Service: Starting MPD Monitor Service Jan 13 17:06:56 volumio sudo[31463]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:56 volumio sudo[31461]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:56 volumio volumio[30805]: info: Successfully started MPD Monitor Jan 13 17:06:56 volumio volumio[30805]: info: Successfully started MPD Monitor Jan 13 17:06:56 volumio volumio[30805]: info: Successfully started MPD Monitor Jan 13 17:06:58 volumio volumio[30805]: info: Getting Spotify volume Jan 13 17:06:58 volumio volumio[30805]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 17:06:58 volumio volumio[30805]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 17:06:58 volumio volumio[30805]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 13 17:06:58 volumio volumio[30805]: errno: -111, Jan 13 17:06:58 volumio volumio[30805]: code: 'ECONNREFUSED', Jan 13 17:06:58 volumio volumio[30805]: syscall: 'connect', Jan 13 17:06:58 volumio volumio[30805]: address: '127.0.0.1', Jan 13 17:06:58 volumio volumio[30805]: port: 9879, Jan 13 17:06:58 volumio volumio[30805]: response: undefined Jan 13 17:06:58 volumio volumio[30805]: } Jan 13 17:06:58 volumio volumio[30805]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 17:06:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 13 17:06:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:06:58 volumio go-librespot[31485]: go-librespot daemon starting... Jan 13 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-06:00" level=debug msg="app state loaded" Jan 13 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-06:00" level=debug msg="stored credentials not found" Jan 13 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-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 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-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 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-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 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-06:00" level=info msg="zeroconf server listening on port 34163" Jan 13 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-06:00" level=debug msg="obtained new client token: AAACBa0V6grNXMLdwLpTQHQalzV0HWSwYxDps56cBqBM/INlECILFNdxLzRFeTabhCXLn4B7lfxPkKeqbcY7ZSqXqHTJugeLotdmfJ43OSngBtnF822q3on5KLmnywwSbag7q3Pb+KYEdJDxaQl5vmF/J/aD3v2O5LteoHF8gZvWufTMNmOvDsmZZWEWzsKG5tcxNoN4R6bWibFjBATrbIYSPiKzt4lAvgWcExJ7wwaaDrVM8sHPQg4+Yg==" Jan 13 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-06:00" level=debug msg="completed keyexchange" Jan 13 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-06:00" level=debug msg="completed challenge" Jan 13 17:06:58 volumio sudo[31495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-13 17:05' Jan 13 17:06:58 volumio sudo[31495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:06:58 volumio go-librespot[31486]: time="2026-01-13T17:06:58-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 17:06:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:06:59 volumio sudo[31495]: pam_unix(sudo:session): session closed for user root Jan 13 17:06:59 volumio volumio-remote-updater[14193]: [2026-01-13 17:06:59] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 13 17:06:59 volumio volumio-remote-updater[14193]: [2026-01-13 17:06:59] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 13 17:06:59 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:06:59 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 13 17:06:59 volumio systemd[1]: volumio.service: Consumed 42.658s CPU time. Jan 13 17:06:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 13 17:06:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 13 17:06:59 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 23331. Jan 13 17:06:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 13 17:06:59 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 13 17:06:59 volumio systemd[1]: volumio.service: Consumed 42.658s CPU time. Jan 13 17:06:59 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 13 17:06:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 13 17:07:00 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.84.206 Jan 13 17:07:00 volumio avahi-daemon[664]: Registering new address record for 169.254.84.206 on eth0.IPv4. Jan 13 17:07:00 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:07:00 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:00 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:07:00 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.84.206 Jan 13 17:07:01 volumio ntpd[872]: IO: Listen normally on 14733 eth0 169.254.84.206:123 Jan 13 17:07:01 volumio ntpd[872]: IO: new interface(s) found: waking up resolver Jan 13 17:07:01 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.84.206 Jan 13 17:07:01 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.84.206 Jan 13 17:07:01 volumio avahi-daemon[664]: Withdrawing address record for 169.254.84.206 on eth0. Jan 13 17:07:01 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:07:01 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:01 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:07:01 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:01 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:07:01 volumio volumio[31521]: info: ------------------------------------------- Jan 13 17:07:01 volumio volumio[31521]: info: ----- Volumio3 ---- Jan 13 17:07:01 volumio volumio[31521]: info: ------------------------------------------- Jan 13 17:07:01 volumio volumio[31521]: info: ----- System startup ---- Jan 13 17:07:01 volumio volumio[31521]: info: ------------------------------------------- Jan 13 17:07:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 13 17:07:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:02 volumio go-librespot[31574]: go-librespot daemon starting... Jan 13 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-06:00" level=debug msg="app state loaded" Jan 13 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-06:00" level=debug msg="stored credentials not found" Jan 13 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-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 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-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 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-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 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-06:00" level=info msg="zeroconf server listening on port 42149" Jan 13 17:07:02 volumio volumio[31521]: info: MYVOLUMIO Environment detected Jan 13 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-06:00" level=debug msg="obtained new client token: AABee4dWarJpBKYiAUgmbKVqGusKZ+8ZAMMy1R8dcWku9jbVgO0wNIDARrM2hk4+lVUiDnpD/3fUGjnRmXNClxiqaxTFn4qVbvd6JrRdIFsRtUMx34kjqVH+N+Om/cPXNdbhEU88CFp5XO7Dns4aX5R5Jc94vG7A+ERXI+nzYdMB2ZpTvXp2eKYS+3lN3IU+lHCBUX5FnRvQ3B53wnsUP4oEO83eKDKjKvGwUMEYgrRXhI7bdQD4zR84jA==" Jan 13 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:07:02 volumio volumio[31521]: info: Plugin folders cleanup Jan 13 17:07:02 volumio volumio[31521]: info: Scanning into folder /volumio/app/plugins/ Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category audio_interface Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category miscellanea Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category music_service Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category plugins.json Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category system_controller Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category user_interface Jan 13 17:07:02 volumio volumio[31521]: info: Scanning into folder /data/plugins/ Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category audio_interface Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category music_service Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category system_controller Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category system_hardware Jan 13 17:07:02 volumio volumio[31521]: info: Scanning category user_interface Jan 13 17:07:02 volumio volumio[31521]: info: Plugin folders cleanup completed Jan 13 17:07:02 volumio volumio[31521]: info: ------------------------------------------- Jan 13 17:07:02 volumio volumio[31521]: info: ----- Core plugins startup ---- Jan 13 17:07:02 volumio volumio[31521]: info: ------------------------------------------- Jan 13 17:07:02 volumio volumio[31521]: info: Loading plugins from folder /volumio/app/plugins/ Jan 13 17:07:02 volumio volumio[31521]: info: Adding plugin upnp to MyMusic Plugins Jan 13 17:07:02 volumio volumio[31521]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 13 17:07:02 volumio volumio[31521]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 13 17:07:02 volumio volumio[31521]: info: Loading plugins from folder /data/plugins/ Jan 13 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-06:00" level=debug msg="completed keyexchange" Jan 13 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-06:00" level=debug msg="completed challenge" Jan 13 17:07:02 volumio volumio[31521]: info: Loading plugin "system"... Jan 13 17:07:02 volumio go-librespot[31575]: time="2026-01-13T17:07:02-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 17:07:02 volumio volumio[31521]: info: Loading plugin "appearance"... Jan 13 17:07:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:07:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:07:03 volumio ntpd[872]: IO: Deleting interface #14733 eth0, 169.254.84.206#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Jan 13 17:07:03 volumio volumio[31521]: info: Loading plugin "network"... Jan 13 17:07:03 volumio volumio[31521]: info: Refreshing Cached IP Addresses Jan 13 17:07:03 volumio sudo[31589]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 17:07:03 volumio sudo[31589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:03 volumio sudo[31589]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:03 volumio sudo[31591]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 17:07:03 volumio volumio[31521]: info: Loading plugin "services"... Jan 13 17:07:03 volumio sudo[31591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:03 volumio volumio[31521]: info: Loading plugin "alsa_controller"... Jan 13 17:07:03 volumio sudo[31598]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 13 17:07:03 volumio sudo[31591]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:03 volumio sudo[31598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:03 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 17:07:03 volumio volumio[31521]: info: Loading plugin "wizard"... Jan 13 17:07:03 volumio volumio[31521]: info: Loading plugin "networkfs"... Jan 13 17:07:03 volumio volumio[31521]: info: Starting Udev Watcher for removable devices Jan 13 17:07:03 volumio volumio[31521]: info: Ignoring mount for partition: boot Jan 13 17:07:03 volumio volumio[31521]: info: Ignoring mount for partition: volumio Jan 13 17:07:03 volumio volumio[31521]: info: Ignoring mount for partition: volumio_data Jan 13 17:07:04 volumio volumio[31521]: info: Mounting Device Wikipedia Jan 13 17:07:04 volumio sudo[31628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 13 17:07:04 volumio sudo[31628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:04 volumio sudo[31628]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:04 volumio volumio[31521]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 13 17:07:04 volumio volumio[31521]: dmesg(1) may have more information after failed mount system call. Jan 13 17:07:04 volumio volumio[31521]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 13 17:07:04 volumio volumio[31521]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 13 17:07:04 volumio volumio[31521]: dmesg(1) may have more information after failed mount system call. Jan 13 17:07:04 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 17:07:04 volumio volumio[31521]: info: Loading plugin "volumio_command_line_client"... Jan 13 17:07:04 volumio volumio[31521]: info: Loading plugin "upnp"... Jan 13 17:07:04 volumio volumio[31521]: info: [1768345624139] Starting Upmpd Daemon Jan 13 17:07:04 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 17:07:04 volumio volumio[31521]: info: Loading plugin "my_music"... Jan 13 17:07:04 volumio volumio[31521]: info: Loading plugin "mpd"... Jan 13 17:07:04 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 17:07:04 volumio volumio-remote-updater[14193]: [2026-01-13 17:07:04] [connect] Successful connection Jan 13 17:07:04 volumio sudo[31598]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:04 volumio volumio[31521]: info: Loading plugin "upnp_browser"... Jan 13 17:07:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 13 17:07:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:06 volumio go-librespot[31631]: go-librespot daemon starting... Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-06:00" level=debug msg="app state loaded" Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-06:00" level=debug msg="stored credentials not found" Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:07:06 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.178.79 Jan 13 17:07:06 volumio avahi-daemon[664]: Registering new address record for 169.254.178.79 on eth0.IPv4. Jan 13 17:07:06 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:07:06 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:06 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:07:06 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.178.79 Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-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 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-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 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-06:00" level=info msg="zeroconf server listening on port 36961" Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-06:00" level=debug msg="obtained new client token: AAA+gjXcTf3G6J0InVKpRny0ICjYSP9HY0XCCNI2M7lxHfj4jm8poV4YX6w+XE+S3E6cgl0fygrwxcK3NmtFMaJeNGM4fXL+rWMJPVRhkH7vDirUhQGu0ff/6qxNcrmCbLNeVS4RksBHuYP4riRDApF+DqAvBSPe/hKWOjVpzY+Co9yW2KD2bqx7+O4g94CYwQF4SfECGZRdvaiet7rPXydLKmOXqGe0lURsWdxMqNDPJC62VRcf7NkPlQ==" Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-06:00" level=debug msg="completed keyexchange" Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-06:00" level=debug msg="completed challenge" Jan 13 17:07:06 volumio go-librespot[31632]: time="2026-01-13T17:07:06-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 17:07:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:07:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:07:07 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.178.79 Jan 13 17:07:07 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.178.79 Jan 13 17:07:07 volumio avahi-daemon[664]: Withdrawing address record for 169.254.178.79 on eth0. Jan 13 17:07:07 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:07:07 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:07 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:07:07 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:07:07 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:07 volumio volumio[31521]: info: Loading plugin "alarm-clock"... Jan 13 17:07:07 volumio volumio[31521]: info: Loading plugin "airplay_emulation"... Jan 13 17:07:07 volumio volumio[31521]: info: Starting Shairport Sync Jan 13 17:07:07 volumio volumio[31521]: info: Loading plugin "last_100"... Jan 13 17:07:07 volumio volumio[31521]: info: Loading plugin "webradio"... Jan 13 17:07:07 volumio volumio[31521]: info: Loading plugin "i2s_dacs"... Jan 13 17:07:07 volumio volumio[31521]: info: I2S DAC not set, start Auto-detection Jan 13 17:07:07 volumio volumio[31521]: info: Loading plugin "volumiodiscovery"... Jan 13 17:07:07 volumio volumio[31521]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 13 17:07:07 volumio volumio[31521]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 17:07:07 volumio volumio[31521]: *** WARNING *** For more information see Jan 13 17:07:07 volumio volumio[31521]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 13 17:07:07 volumio volumio[31521]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 17:07:07 volumio volumio[31521]: *** WARNING *** For more information see Jan 13 17:07:07 volumio node[31521]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 13 17:07:07 volumio node[31521]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 17:07:07 volumio node[31521]: *** WARNING *** For more information see Jan 13 17:07:07 volumio node[31521]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 13 17:07:07 volumio node[31521]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 13 17:07:07 volumio node[31521]: *** WARNING *** For more information see Jan 13 17:07:07 volumio volumio[31521]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 13 17:07:07 volumio volumio[31521]: info: Discovery: Started advertising with name: Volumio Jan 13 17:07:07 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 17:07:07 volumio volumio[31521]: info: Loading plugin "bandcamp"... Jan 13 17:07:09 volumio volumio[31521]: info: Plugin calmradio is not enabled Jan 13 17:07:09 volumio volumio[31521]: info: Loading plugin "soundcloud"... Jan 13 17:07:09 volumio volumio[31521]: info: Loading plugin "spop"... Jan 13 17:07:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 13 17:07:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:10 volumio go-librespot[31674]: go-librespot daemon starting... Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-06:00" level=debug msg="app state loaded" Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-06:00" level=debug msg="stored credentials not found" Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:07:10 volumio volumio[31521]: info: Loading plugin "squeezelite_mc"... Jan 13 17:07:10 volumio kernel: hwmon hwmon1: Voltage normalised Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-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 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-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 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-06:00" level=info msg="zeroconf server listening on port 45347" Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-06:00" level=debug msg="obtained new client token: AAAmPjYRZ/CfRTZ8VYp/rYXYJ0z4n2sHfH623DNshIhqKqp17iU9gqGz57L7dqMlerAf4G6ucRHu7O65fy6zJ7ryg1SK2brflXD8ob9+FO6W/dlPAdpyv/GDjTYrpw+7unjXj59v9MY67ZOXesHFuxQ8ythTLTiiHYgal24pNRm9oLMU8Nxkij35rVfPiMsUijWkaLiEnlkfNmo4v85bH5/sdlGELuyCJ2rT9EXXeI7iBo0PikRge/1sGQ==" Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-06:00" level=debug msg="completed keyexchange" Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-06:00" level=debug msg="completed challenge" Jan 13 17:07:10 volumio go-librespot[31675]: time="2026-01-13T17:07:10-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 17:07:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:07:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:07:11 volumio volumio[31521]: info: Loading plugin "youtube2"... Jan 13 17:07:11 volumio volumio[31521]: info: Loading plugin "ytcr"... Jan 13 17:07:12 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.206.202 Jan 13 17:07:12 volumio avahi-daemon[664]: Registering new address record for 169.254.206.202 on eth0.IPv4. Jan 13 17:07:12 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:07:12 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:12 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:07:12 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:13 volumio volumio[31521]: info: Loading plugin "ytmusic"... Jan 13 17:07:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.206.202 Jan 13 17:07:13 volumio volumio[31521]: info: Plugin now_playing is not enabled Jan 13 17:07:13 volumio volumio[31521]: info: Loading plugin "outputs"... Jan 13 17:07:13 volumio volumio[31521]: info: Loading plugin "albumart"... Jan 13 17:07:13 volumio volumio[31521]: info: Plugin example_plugin is not enabled Jan 13 17:07:13 volumio volumio[31521]: info: Loading plugin "inputs"... Jan 13 17:07:13 volumio volumio[31521]: info: Loading plugin "updater_comm"... Jan 13 17:07:13 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.206.202 Jan 13 17:07:13 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.206.202 Jan 13 17:07:13 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:07:13 volumio avahi-daemon[664]: Withdrawing address record for 169.254.206.202 on eth0. Jan 13 17:07:13 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:13 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:07:13 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:13 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:07:13 volumio volumio[31521]: info: Plugin mpdemulation is not enabled Jan 13 17:07:13 volumio volumio[31521]: info: Loading plugin "rest_api"... Jan 13 17:07:13 volumio volumio[31521]: info: Loading plugin "websocket"... Jan 13 17:07:13 volumio volumio[31521]: info: Starting Socket.io Server version 1.7.4 Jan 13 17:07:13 volumio volumio[31521]: info: Plugin fusiondsp is not enabled Jan 13 17:07:13 volumio volumio[31521]: info: Plugin mpdoutput is not enabled Jan 13 17:07:13 volumio volumio[31521]: info: Plugin RoonBridge is not enabled Jan 13 17:07:13 volumio volumio[31521]: info: Loading plugin "podcast"... Jan 13 17:07:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 13 17:07:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:14 volumio go-librespot[31739]: go-librespot daemon starting... Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=debug msg="app state loaded" Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=debug msg="stored credentials not found" Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:07:14 volumio volumio[31521]: info: ControllerPodcast::constructor Jan 13 17:07:14 volumio volumio[31521]: info: Loading plugin "volusonic"... Jan 13 17:07:14 volumio volumio[31699]: Forking 3 albumart workers Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=info msg="zeroconf server listening on port 40743" Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=debug msg="obtained new client token: AADmbIvNBmlAKge4pj/4kqUgDYYKixeYkyI9ne/iBSSxOY4NZ1Cs0dE3i1Ptauk/gAQA/jQ4JPSiPVe8PToom1qTl5GQTOKwWaR9cy+R2xqiZaWcrP2F3k2RdsmMjnJx/w3WieCxZ9BsXCdFxagJOdZsMxEbmxwHjU871lnlAziAV68kR0uY4Hjd+5ltkPrvcgytgqUTp1zU+fs5BOG++g3P3Yf30B1w8zgAORvTWhGUWZUUTfrC7VJ/VA==" Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=debug msg="completed keyexchange" Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=debug msg="completed challenge" Jan 13 17:07:14 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 13 17:07:14 volumio go-librespot[31740]: time="2026-01-13T17:07:14-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 17:07:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:07:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:07:16 volumio volumio[31521]: info: Applying required configuration parameters for plugin volusonic Jan 13 17:07:16 volumio volumio[31521]: info: Loading plugin "backup_restore"... Jan 13 17:07:16 volumio volumio[31749]: Starting albumart workers Jan 13 17:07:16 volumio volumio-remote-updater[14193]: [2026-01-13 17:07:16] [connect] Successful connection Jan 13 17:07:16 volumio volumio[31748]: Starting albumart workers Jan 13 17:07:16 volumio volumio[31750]: Starting albumart workers Jan 13 17:07:17 volumio volumio[31521]: info: Applying required configuration parameters for plugin backup_restore Jan 13 17:07:17 volumio volumio[31521]: info: Plugin rpi_eeprom_config is not enabled Jan 13 17:07:17 volumio volumio[31521]: info: Plugin rpi_eeprom_updater is not enabled Jan 13 17:07:17 volumio volumio[31521]: info: Loading plugin "scheduledrestart"... Jan 13 17:07:17 volumio volumio[31521]: info: Applying required configuration parameters for plugin scheduledrestart Jan 13 17:07:17 volumio volumio[31521]: info: Plugin Bluetoothremote is not enabled Jan 13 17:07:17 volumio volumio[31521]: info: Plugin music_services_shield is not enabled Jan 13 17:07:17 volumio volumio[31521]: info: Loading plugin "Systeminfo"... Jan 13 17:07:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 13 17:07:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:18 volumio go-librespot[31783]: go-librespot daemon starting... Jan 13 17:07:18 volumio volumio[31521]: info: Plugin peppymeterbasic is not enabled Jan 13 17:07:18 volumio volumio[31521]: info: Loading plugin "peppyspectrum"... Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=debug msg="app state loaded" Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=debug msg="stored credentials not found" Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-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 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-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 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=info msg="zeroconf server listening on port 33891" Jan 13 17:07:18 volumio volumio[31521]: info: Loading i18n strings for locale en Jan 13 17:07:18 volumio volumio[31521]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 17:07:18 volumio volumio[31521]: Updating browse sources language Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=debug msg="obtained new client token: AAAKGWG5rYQz7PgCH9Gq0B1dBB4vH6lz8GGDwkxBFeGWJzrqtuPwnnfQbx3XDodOAxKvoHViu0jtIh2gA8D87bAL5a/5yniRyNRqgdT4avU8MxB1vKYzpUtjMfGLOwf1ZICs+RRBAahOGhftrP+czXuCKi5pVMZObLPr4qiMnU7jyvbM8FbR/gnI+z7VWMrDJN2/lplD939ihlziHrSWhgR7k3r8l9QbHqFPKTW3UnyfYCWrsVQ0aUiJuA==" Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=debug msg="completed keyexchange" Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=debug msg="completed challenge" Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::initPlayerControls Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:07:18 volumio volumio[31521]: Express server listening on port 3000 Jan 13 17:07:18 volumio volumio[31521]: [Metrics] WebUI: 17s 533.86ms Jan 13 17:07:18 volumio volumio[31521]: info: CoreStateMachine::resetVolumioState Jan 13 17:07:18 volumio volumio[31521]: info: CoreStateMachine::getcurrentVolume Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 17:07:18 volumio go-librespot[31793]: time="2026-01-13T17:07:18-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 17:07:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:07:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:07:18 volumio sudo[31814]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 17:07:18 volumio sudo[31814]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:18 volumio sudo[31816]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 17:07:18 volumio sudo[31816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:18 volumio sudo[31814]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:18 volumio sudo[31816]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:18 volumio volumio[31521]: info: Volumio Network Manager: Network status updated: 1 Jan 13 17:07:18 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.176.233 Jan 13 17:07:18 volumio avahi-daemon[664]: Registering new address record for 169.254.176.233 on eth0.IPv4. Jan 13 17:07:18 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:07:18 volumio volumio[31521]: info: VolumeController:: Volume=100 Mute =false Jan 13 17:07:18 volumio volumio[31521]: info: CoreStateMachine::pushState Jan 13 17:07:18 volumio volumio[31521]: info: CorePlayQueue::getTrack 0 Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::volumioPushState Jan 13 17:07:18 volumio volumio[31521]: info: CoreStateMachine::updateTrackBlock Jan 13 17:07:18 volumio volumio[31521]: info: CorePlayQueue::getTrackBlock Jan 13 17:07:18 volumio volumio[31521]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 17:07:19 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:19 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:07:19 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:19 volumio volumio-remote-updater[14193]: [2026-01-13 17:07:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768345636 101 Jan 13 17:07:19 volumio volumio[31521]: 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 17:07:19 volumio volumio[31521]: info: Reloading queue from file Jan 13 17:07:19 volumio volumio[31521]: info: CoreStateMachine::setRepeat null single undefined Jan 13 17:07:19 volumio volumio[31521]: info: CoreStateMachine::pushState Jan 13 17:07:19 volumio volumio[31521]: info: CorePlayQueue::getTrack 0 Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::volumioPushState Jan 13 17:07:19 volumio volumio[31521]: info: CoreStateMachine::setRandom null Jan 13 17:07:19 volumio volumio[31521]: info: CoreStateMachine::pushState Jan 13 17:07:19 volumio volumio[31521]: info: CorePlayQueue::getTrack 0 Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::volumioPushState Jan 13 17:07:19 volumio volumio[31521]: info: Setting Device type: Raspberry PI Jan 13 17:07:19 volumio volumio[31521]: info: VolumeController:: Volume=100 Mute =false Jan 13 17:07:19 volumio volumio[31521]: info: CoreStateMachine::pushState Jan 13 17:07:19 volumio volumio[31521]: info: CorePlayQueue::getTrack 0 Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::volumioPushState Jan 13 17:07:19 volumio volumio[31521]: info: Completed loading Core Plugins Jan 13 17:07:19 volumio volumio[31521]: info: Preparing to generate the ALSA configuration file Jan 13 17:07:19 volumio sudo[31846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 13 17:07:19 volumio sudo[31846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:19 volumio volumio[31521]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 17:07:19 volumio volumio[31521]: info: Discovery: Found device Volumio Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::volumioGetState Jan 13 17:07:19 volumio volumio[31521]: info: CorePlayQueue::getTrack 0 Jan 13 17:07:19 volumio volumio[31521]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 17:07:19 volumio volumio[31521]: info: Reading ALSA contributions from plugins. Jan 13 17:07:19 volumio volumio[31521]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 13 17:07:19 volumio sudo[31846]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:19 volumio volumio[31521]: info: Discovery: Found device Volumio Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::volumioGetState Jan 13 17:07:19 volumio volumio[31521]: info: CorePlayQueue::getTrack 0 Jan 13 17:07:19 volumio volumio[31521]: info: Upmpdcli Daemon Started Jan 13 17:07:19 volumio volumio[31521]: info: Asound.conf file unchanged, so no further update is needed Jan 13 17:07:19 volumio volumio[31521]: info: Output device has changed, restarting MPD Jan 13 17:07:19 volumio volumio[31521]: info: Output device has changed, restarting Shairport Sync Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:07:19 volumio sudo[31849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 17:07:19 volumio sudo[31849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:19 volumio sudo[31851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 17:07:19 volumio sudo[31851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:19 volumio sudo[31849]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:19 volumio volumio[31521]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:07:19 volumio volumio[31521]: info: ___________ START PLUGINS ___________ Jan 13 17:07:19 volumio volumio[31521]: info: ControllerMpd::onStart: Initializing MPD Jan 13 17:07:19 volumio volumio[31521]: info: Creating MPD Configuration file Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:07:19 volumio volumio[31521]: info: [1768345639331] CoreMusicLibrary::Adding element Media Servers Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:19 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 13 17:07:19 volumio sudo[31861]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 17:07:19 volumio sudo[31861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:19 volumio sudo[31859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 17:07:19 volumio sudo[31859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:07:19 volumio sudo[31859]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:19 volumio volumio[31521]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:07:19 volumio volumio[31521]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:07:19 volumio volumio[31521]: info: [1768345639450] CoreMusicLibrary::Adding element Last_100 Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:07:19 volumio volumio[31521]: info: [1768345639454] CoreMusicLibrary::Adding element Webradio Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 17:07:19 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 17:07:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 17:07:19 volumio systemd[1]: mpd.service: Consumed 3.895s CPU time. Jan 13 17:07:19 volumio volumio[31521]: info: Initializing BBC Radios Jan 13 17:07:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 17:07:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 17:07:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 17:07:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 17:07:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:07:19 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.176.233 Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:07:19 volumio volumio[31521]: info: [1768345639572] CoreMusicLibrary::Adding element Bandcamp Discover Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:19 volumio volumio[31521]: Cannot find translation for source Bandcamp Discover Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:07:19 volumio volumio[31521]: info: [1768345639592] CoreMusicLibrary::Adding element SoundCloud Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:19 volumio volumio[31521]: Cannot find translation for source Bandcamp Discover Jan 13 17:07:19 volumio volumio[31521]: Cannot find translation for source SoundCloud Jan 13 17:07:19 volumio volumio[31521]: info: Creating Spotify config file Jan 13 17:07:19 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:19 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.176.233 Jan 13 17:07:19 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.176.233 Jan 13 17:07:19 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:07:19 volumio avahi-daemon[664]: Withdrawing address record for 169.254.176.233 on eth0. Jan 13 17:07:19 volumio sudo[31886]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 17:07:19 volumio sudo[31886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 17:07:19 volumio sudo[31886]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:20 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:07:20 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:20 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:07:20 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:20 volumio volumio[31521]: info: [squeezelite_mc] Starting proxy server... Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:07:20 volumio volumio[31521]: info: [1768345640308] CoreMusicLibrary::Adding element YouTube2 Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Bandcamp Discover Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source SoundCloud Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube2 Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:07:20 volumio volumio[31521]: info: [1768345640340] CoreMusicLibrary::Adding element YouTube Music Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Bandcamp Discover Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source SoundCloud Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube2 Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube Music Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:07:20 volumio volumio[31521]: info: [1768345640360] CoreMusicLibrary::Adding element Podcast Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Bandcamp Discover Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source SoundCloud Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube2 Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube Music Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Podcast Jan 13 17:07:20 volumio volumio[31521]: info: Loading i18n strings for locale en Jan 13 17:07:20 volumio volumio[31521]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 13 17:07:20 volumio volumio[31521]: Updating browse sources language Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Bandcamp Discover Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source SoundCloud Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube2 Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube Music Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Podcast Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Bandcamp Discover Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source SoundCloud Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube2 Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube Music Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Podcast Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:07:20 volumio volumio[31521]: info: [1768345640444] CoreMusicLibrary::Adding element Volusonic Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Bandcamp Discover Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source SoundCloud Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube2 Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source YouTube Music Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Podcast Jan 13 17:07:20 volumio volumio[31521]: Cannot find translation for source Volusonic Jan 13 17:07:20 volumio volumio[31521]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 13 17:07:20 volumio volumio[31521]: info: Volumio Calling Home Jan 13 17:07:20 volumio volumio[31521]: info: [squeezelite_mc] Proxy server started on port 39763 Jan 13 17:07:20 volumio volumio[31521]: info: Preparing to generate the ALSA configuration file Jan 13 17:07:20 volumio volumio[31521]: info: CoreCommandRouter::volumioRetrievevolume Jan 13 17:07:20 volumio volumio[31521]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 13 17:07:20 volumio volumio[31521]: info: Reading ALSA contributions from plugins. Jan 13 17:07:21 volumio volumio[31521]: info: MPD Permissions set Jan 13 17:07:21 volumio volumio[31521]: info: MPD Permissions set Jan 13 17:07:21 volumio volumio[31521]: info: Spotify config file written Jan 13 17:07:21 volumio sudo[31911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 13 17:07:21 volumio sudo[31911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:21 volumio volumio[31521]: 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 17:07:21 volumio volumio[31521]: info: VolumeController:: Volume=100 Mute =false Jan 13 17:07:21 volumio volumio[31521]: info: CoreStateMachine::pushState Jan 13 17:07:21 volumio volumio[31521]: info: CorePlayQueue::getTrack 0 Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::volumioPushState Jan 13 17:07:21 volumio volumio[31521]: info: [squeezelite_mc] Server discovery started Jan 13 17:07:21 volumio volumio[31521]: info: [squeezelite_mc] Player finder started Jan 13 17:07:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:07:21 volumio sudo[31911]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:21 volumio volumio[31521]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 13 17:07:21 volumio go-librespot[31913]: go-librespot daemon starting... Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio go-librespot[31914]: time="2026-01-13T17:07:21-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:07:21 volumio go-librespot[31914]: time="2026-01-13T17:07:21-06:00" level=debug msg="app state loaded" Jan 13 17:07:21 volumio go-librespot[31914]: time="2026-01-13T17:07:21-06:00" level=debug msg="stored credentials not found" Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio go-librespot[31914]: time="2026-01-13T17:07:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:21 volumio volumio[31521]: info: No need to fix Spotify hosts Jan 13 17:07:21 volumio volumio[31521]: 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 17:07:21 volumio volumio[31521]: info: Volumio called home Jan 13 17:07:21 volumio go-librespot[31914]: time="2026-01-13T17:07:21-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 17:07:21 volumio go-librespot[31914]: time="2026-01-13T17:07:21-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 17:07:21 volumio go-librespot[31914]: time="2026-01-13T17:07:21-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 17:07:21 volumio go-librespot[31914]: time="2026-01-13T17:07:21-06:00" level=info msg="zeroconf server listening on port 45399" Jan 13 17:07:21 volumio volumio[31521]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 13 17:07:21 volumio volumio[31521]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 13 17:07:21 volumio volumio[31521]: 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 17:07:22 volumio volumio[31521]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 17:07:22 volumio volumio[31521]: SPOTIFY: BQACCtilcsAaJ4saxgxPVzysljS00GYHtPy5yz6fvMAsb0k7L9dFTMHPlE4Ftjtkgd2vHeFeu69i4Sy-3waPN4xow3feMPjJO_kAucOMimx3f_YhjwTlkyQ4U2P4SY11mwanWLWpJG5vBZwHLCAWmzFHkAkqeFK0e6QIy23Xeo7BeoeP7rx7l_TQudQk3nibgBbRGYvu-oGigRJpzW_08wHpeWxlcRlVPoTag3c Jan 13 17:07:22 volumio volumio[31521]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 13 17:07:22 volumio volumio[31521]: info: New Spotify access token = BQACCtilcsAaJ4saxgxPVzysljS00GYHtPy5yz6fvMAsb0k7L9dFTMHPlE4Ftjtkgd2vHeFeu69i4Sy-3waPN4xow3feMPjJO_kAucOMimx3f_YhjwTlkyQ4U2P4SY11mwanWLWpJG5vBZwHLCAWmzFHkAkqeFK0e6QIy23Xeo7BeoeP7rx7l_TQudQk3nibgBbRGYvu-oGigRJpzW_08wHpeWxlcRlVPoTag3c Jan 13 17:07:22 volumio volumio[31521]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 13 17:07:22 volumio go-librespot[31914]: time="2026-01-13T17:07:22-06:00" level=debug msg="obtained new client token: AADJBmngjTuTzB5SK/4pwzEqgxBbaeHQG8F06OUAo8qBMGwQkvEPaCzwT6rSvG+QynMqFDA45QPXafCTIgblAXeDdzrUi0NvHGtA7zK+hN9a1ot+ARowpng0cq2cHl9QUJdWFabT28sbh2v2cA1dyp28kZeIiNw8jT880f/FcRr+moat7uPRnWfQM9GK+/4z92dQ8ZPC8rFK7xpNdQWJy3E4J5lTGhROboDn+/4TSnHVG76erQxeJc8=" Jan 13 17:07:22 volumio volumio[31521]: info: Starting Shairport Sync Jan 13 17:07:22 volumio volumio[31521]: info: Starting Shairport Sync Jan 13 17:07:22 volumio volumio[31521]: info: Starting Shairport Sync Jan 13 17:07:22 volumio go-librespot[31914]: time="2026-01-13T17:07:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 17:07:22 volumio sudo[31938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:07:22 volumio sudo[31938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:22 volumio sudo[31940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:07:22 volumio sudo[31940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:22 volumio go-librespot[31914]: time="2026-01-13T17:07:22-06:00" level=debug msg="completed keyexchange" Jan 13 17:07:22 volumio sudo[31942]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:07:22 volumio sudo[31942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:22 volumio go-librespot[31914]: time="2026-01-13T17:07:22-06:00" level=debug msg="completed challenge" Jan 13 17:07:22 volumio go-librespot[31914]: time="2026-01-13T17:07:22-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 13 17:07:22 volumio volumio[31521]: info: Asound.conf file unchanged, so no further update is needed Jan 13 17:07:22 volumio volumio[31521]: info: Output device has changed, restarting MPD Jan 13 17:07:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 17:07:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 17:07:22 volumio volumio[31521]: info: Output device has changed, restarting Shairport Sync Jan 13 17:07:22 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:22 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:07:22 volumio sudo[31936]: 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 17:07:22 volumio sudo[31936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:22 volumio sudo[31936]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:22 volumio sudo[31947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 17:07:22 volumio sudo[31947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:22 volumio sudo[31947]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:22 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 17:07:22 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 17:07:22 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:07:22 volumio systemd[1]: shairport-sync.service: Consumed 2.016s CPU time. Jan 13 17:07:22 volumio volumio[31521]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 13 17:07:22 volumio sudo[31950]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 17:07:22 volumio sudo[31950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:07:22 volumio sudo[31942]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:22 volumio sudo[31938]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:22 volumio sudo[31940]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:22 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 13 17:07:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 13 17:07:22 volumio systemd[1]: mpd.service: Consumed 3.035s CPU time. Jan 13 17:07:22 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 13 17:07:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 13 17:07:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 13 17:07:22 volumio volumio[31521]: info: MPD Permissions set Jan 13 17:07:22 volumio volumio[31521]: info: Shairport-Sync Started Jan 13 17:07:22 volumio volumio[31521]: Error adding Membership: Error: addMembership EINVAL Jan 13 17:07:22 volumio volumio[31521]: info: Shairport-Sync Started Jan 13 17:07:22 volumio volumio[31521]: info: Shairport-Sync Started Jan 13 17:07:22 volumio volumio[31521]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 13 17:07:22 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 13 17:07:22 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 13 17:07:22 volumio sudo[31979]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 13 17:07:22 volumio sudo[31979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:22 volumio sudo[31979]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:22 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:22 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:22 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:22 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:22 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:22 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:22 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:22 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:23 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 17:07:23 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:23 volumio volumio[31521]: 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 17:07:23 volumio volumio[31521]: info: CoreCommandRouter::volumioGetState Jan 13 17:07:23 volumio volumio[31521]: info: CorePlayQueue::getTrack 0 Jan 13 17:07:23 volumio volumio[31521]: info: Starting Shairport Sync Jan 13 17:07:23 volumio volumio[31521]: 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 17:07:23 volumio volumio[31521]: info: Spotify Successfully logged in Jan 13 17:07:23 volumio volumio[31521]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 17:07:23 volumio volumio[31521]: info: [1768345643178] CoreMusicLibrary::Adding element Spotify Jan 13 17:07:23 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 17:07:23 volumio volumio[31521]: Cannot find translation for source Bandcamp Discover Jan 13 17:07:23 volumio volumio[31521]: Cannot find translation for source SoundCloud Jan 13 17:07:23 volumio volumio[31521]: Cannot find translation for source YouTube2 Jan 13 17:07:23 volumio volumio[31521]: Cannot find translation for source YouTube Music Jan 13 17:07:23 volumio volumio[31521]: Cannot find translation for source Podcast Jan 13 17:07:23 volumio volumio[31521]: Cannot find translation for source Volusonic Jan 13 17:07:23 volumio volumio[31521]: Cannot find translation for source Spotify Jan 13 17:07:23 volumio sudo[31991]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 13 17:07:23 volumio sudo[31991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:23 volumio sudo[31980]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 17:07:23 volumio sudo[31980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 13 17:07:23 volumio sudo[31980]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:23 volumio sudo[31989]: 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 17:07:23 volumio sudo[31989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 13 17:07:23 volumio sudo[31989]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 13 17:07:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:07:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 13 17:07:23 volumio volumio[31521]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 13 17:07:23 volumio sudo[31991]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:23 volumio volumio[31521]: info: Shairport-Sync Started Jan 13 17:07:23 volumio sudo[31998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 13 17:07:23 volumio sudo[31998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:23 volumio systemd[1]: Reloading. Jan 13 17:07:24 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:24 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:24 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 17:07:24 volumio volumio[31521]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 17:07:24 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.58.162 Jan 13 17:07:24 volumio avahi-daemon[664]: Registering new address record for 169.254.58.162 on eth0.IPv4. Jan 13 17:07:24 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 13 17:07:24 volumio volumio[31521]: info: go-librespot daemon successfully initialized Jan 13 17:07:25 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.58.162 Jan 13 17:07:25 volumio volumio[31521]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 17:07:25 volumio volumio[31521]: Error: addMembership ENODEV Jan 13 17:07:25 volumio volumio[31521]: at Socket.addMembership (node:dgram:860:11) Jan 13 17:07:25 volumio volumio[31521]: at addMembership (/volumio/node_modules/node-ssdp/lib/index.js:264:16) { Jan 13 17:07:25 volumio volumio[31521]: errno: -19, Jan 13 17:07:25 volumio volumio[31521]: code: 'ENODEV', Jan 13 17:07:25 volumio volumio[31521]: syscall: 'addMembership' Jan 13 17:07:25 volumio volumio[31521]: } Jan 13 17:07:25 volumio volumio[31521]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 17:07:25 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.58.162 Jan 13 17:07:25 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.58.162 Jan 13 17:07:25 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 13 17:07:25 volumio avahi-daemon[664]: Withdrawing address record for 169.254.58.162 on eth0. Jan 13 17:07:25 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 13 17:07:26 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 13 17:07:26 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 13 17:07:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 13 17:07:27 volumio sudo[31998]: pam_unix(sudo:session): session closed for user root Jan 13 17:07:27 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:27 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:07:27 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:27 volumio sudo[32092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-13 17:06' Jan 13 17:07:27 volumio sudo[32092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 17:07:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 17:07:27 volumio go-librespot[32089]: go-librespot daemon starting... Jan 13 17:07:27 volumio go-librespot[32094]: time="2026-01-13T17:07:27-06:00" level=info msg="running go-librespot 0.4.0" Jan 13 17:07:27 volumio go-librespot[32094]: time="2026-01-13T17:07:27-06:00" level=debug msg="app state loaded" Jan 13 17:07:27 volumio go-librespot[32094]: time="2026-01-13T17:07:27-06:00" level=debug msg="stored credentials not found" Jan 13 17:07:27 volumio go-librespot[32094]: time="2026-01-13T17:07:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 17:07:27 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 13 17:07:27 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 13 17:07:27 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. 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"