Jan 08 20:46:00 volumio volumio[17537]: Starting albumart workers Jan 08 20:46:00 volumio volumio[17536]: Starting albumart workers Jan 08 20:46:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.144.37 Jan 08 20:46:00 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.144.37 Jan 08 20:46:00 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.144.37 Jan 08 20:46:00 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:00 volumio avahi-daemon[664]: Withdrawing address record for 169.254.144.37 on eth0. Jan 08 20:46:00 volumio volumio[17338]: info: Applying required configuration parameters for plugin backup_restore Jan 08 20:46:00 volumio volumio[17338]: info: Plugin rpi_eeprom_config is not enabled Jan 08 20:46:00 volumio volumio[17338]: info: Plugin rpi_eeprom_updater is not enabled Jan 08 20:46:00 volumio volumio[17338]: info: Loading plugin "scheduledrestart"... Jan 08 20:46:00 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:00 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:00 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:00 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:00 volumio volumio[17535]: Starting albumart workers Jan 08 20:46:00 volumio volumio[17338]: info: Applying required configuration parameters for plugin scheduledrestart Jan 08 20:46:00 volumio volumio[17338]: info: Plugin Bluetoothremote is not enabled Jan 08 20:46:00 volumio volumio[17338]: info: Plugin music_services_shield is not enabled Jan 08 20:46:00 volumio volumio[17338]: info: Loading plugin "Systeminfo"... Jan 08 20:46:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Jan 08 20:46:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:01 volumio go-librespot[17599]: go-librespot daemon starting... Jan 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-06:00" level=debug msg="app state loaded" Jan 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:01 volumio volumio[17338]: info: Plugin peppymeterbasic is not enabled Jan 08 20:46:01 volumio volumio[17338]: info: Loading plugin "peppyspectrum"... Jan 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-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 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-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 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-06:00" level=info msg="zeroconf server listening on port 41993" Jan 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-06:00" level=debug msg="obtained new client token: AADTlwC0v8w/QJIbzooj6I5U/it3k7vIpNSkxQy/lqCmn8IXvacCevYdZb8Ix0ehOolyTos9bhSI/lZijsu1rcLF8pMOXog32vaEfgk+Hgue1FN5tI6g4EgnxRhFM9WzVKJtamblsgoHAhH7/pt2QrWPw73ITKdK+l9qO5Oz64iai3wBIZk3zm6ACY9vtbiuih8l/5bdokPlW1uOpqtIrUMOpcRGCkKBJGhoFuyULd0HLPqlGN71U5FvYQ==" Jan 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:01 volumio go-librespot[17600]: time="2026-01-08T20:46:01-06:00" level=debug msg="completed challenge" Jan 08 20:46:02 volumio go-librespot[17600]: time="2026-01-08T20:46: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 08 20:46:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:02 volumio volumio[17338]: info: Loading i18n strings for locale en Jan 08 20:46:02 volumio volumio[17338]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 08 20:46:02 volumio volumio[17338]: Updating browse sources language Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::initPlayerControls Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:46:02 volumio volumio[17338]: Express server listening on port 3000 Jan 08 20:46:02 volumio volumio[17338]: [Metrics] WebUI: 18s 374.71ms Jan 08 20:46:02 volumio volumio[17338]: info: CoreStateMachine::resetVolumioState Jan 08 20:46:02 volumio volumio[17338]: info: CoreStateMachine::getcurrentVolume Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 20:46:02 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:02 volumio sudo[17631]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 20:46:02 volumio sudo[17631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:02 volumio sudo[17631]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:02 volumio sudo[17633]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 20:46:02 volumio sudo[17633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:02 volumio sudo[17633]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:02 volumio volumio[17338]: info: Volumio Network Manager: Network status updated: 1 Jan 08 20:46:02 volumio volumio[17338]: info: VolumeController:: Volume=100 Mute =false Jan 08 20:46:03 volumio volumio[17338]: info: CoreStateMachine::pushState Jan 08 20:46:03 volumio volumio[17338]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioPushState Jan 08 20:46:03 volumio volumio[17338]: info: CoreStateMachine::updateTrackBlock Jan 08 20:46:03 volumio volumio[17338]: info: CorePlayQueue::getTrackBlock Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 20:46:03 volumio volumio-remote-updater[14193]: [2026-01-08 20:46:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767926759 101 Jan 08 20:46:03 volumio volumio[17338]: 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 08 20:46:03 volumio volumio[17338]: info: Reloading queue from file Jan 08 20:46:03 volumio volumio[17338]: info: CoreStateMachine::setRepeat null single undefined Jan 08 20:46:03 volumio volumio[17338]: info: CoreStateMachine::pushState Jan 08 20:46:03 volumio volumio[17338]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioPushState Jan 08 20:46:03 volumio volumio[17338]: info: CoreStateMachine::setRandom null Jan 08 20:46:03 volumio volumio[17338]: info: CoreStateMachine::pushState Jan 08 20:46:03 volumio volumio[17338]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioPushState Jan 08 20:46:03 volumio volumio[17338]: info: Setting Device type: Raspberry PI Jan 08 20:46:03 volumio volumio[17338]: info: VolumeController:: Volume=100 Mute =false Jan 08 20:46:03 volumio volumio[17338]: info: CoreStateMachine::pushState Jan 08 20:46:03 volumio volumio[17338]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioPushState Jan 08 20:46:03 volumio volumio[17338]: info: Completed loading Core Plugins Jan 08 20:46:03 volumio volumio[17338]: info: Preparing to generate the ALSA configuration file Jan 08 20:46:03 volumio sudo[17646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 08 20:46:03 volumio sudo[17646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:03 volumio volumio[17338]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 08 20:46:03 volumio volumio[17338]: info: Discovery: Found device Volumio Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioGetState Jan 08 20:46:03 volumio volumio[17338]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:03 volumio volumio[17338]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 08 20:46:03 volumio volumio[17338]: info: Discovery: Found device Volumio Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioGetState Jan 08 20:46:03 volumio volumio[17338]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:03 volumio volumio[17338]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 08 20:46:03 volumio volumio[17338]: info: Reading ALSA contributions from plugins. Jan 08 20:46:03 volumio volumio[17338]: info: Asound.conf file unchanged, so no further update is needed Jan 08 20:46:03 volumio volumio[17338]: info: Output device has changed, restarting MPD Jan 08 20:46:03 volumio sudo[17646]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:03 volumio volumio[17338]: info: Output device has changed, restarting Shairport Sync Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:03 volumio sudo[17649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 20:46:03 volumio sudo[17651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 20:46:03 volumio sudo[17651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:03 volumio sudo[17649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:03 volumio sudo[17649]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:03 volumio volumio[17338]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:46:03 volumio volumio[17338]: info: ___________ START PLUGINS ___________ Jan 08 20:46:03 volumio volumio[17338]: info: ControllerMpd::onStart: Initializing MPD Jan 08 20:46:03 volumio volumio[17338]: info: Creating MPD Configuration file Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:03 volumio volumio[17338]: info: [1767926763586] CoreMusicLibrary::Adding element Media Servers Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:03 volumio sudo[17659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 20:46:03 volumio sudo[17659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:03 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 08 20:46:03 volumio sudo[17659]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:03 volumio sudo[17661]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 20:46:03 volumio sudo[17661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:03 volumio volumio[17338]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:03 volumio volumio[17338]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:03 volumio volumio[17338]: info: [1767926763779] CoreMusicLibrary::Adding element Last_100 Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:03 volumio volumio[17338]: info: [1767926763791] CoreMusicLibrary::Adding element Webradio Jan 08 20:46:03 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 08 20:46:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:03 volumio systemd[1]: mpd.service: Consumed 4.387s CPU time. Jan 08 20:46:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 08 20:46:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 20:46:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 20:46:03 volumio volumio[17338]: info: Initializing BBC Radios Jan 08 20:46:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 20:46:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:03 volumio volumio[17338]: info: [1767926763927] CoreMusicLibrary::Adding element Bandcamp Discover Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:03 volumio volumio[17338]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:03 volumio volumio[17338]: info: [1767926763946] CoreMusicLibrary::Adding element SoundCloud Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:03 volumio volumio[17338]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:03 volumio volumio[17338]: Cannot find translation for source SoundCloud Jan 08 20:46:03 volumio volumio[17338]: info: Creating Spotify config file Jan 08 20:46:03 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio sudo[17682]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 08 20:46:04 volumio sudo[17682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 08 20:46:04 volumio sudo[17682]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:04 volumio volumio[17338]: info: [squeezelite_mc] Starting proxy server... Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:04 volumio volumio[17338]: info: [1767926764317] CoreMusicLibrary::Adding element YouTube2 Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source SoundCloud Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube2 Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:04 volumio volumio[17338]: info: [1767926764335] CoreMusicLibrary::Adding element YouTube Music Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source SoundCloud Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube2 Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube Music Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:04 volumio volumio[17338]: info: [1767926764347] CoreMusicLibrary::Adding element Podcast Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source SoundCloud Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube2 Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube Music Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Podcast Jan 08 20:46:04 volumio volumio[17338]: info: Loading i18n strings for locale en Jan 08 20:46:04 volumio volumio[17338]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 08 20:46:04 volumio volumio[17338]: Updating browse sources language Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source SoundCloud Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube2 Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube Music Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Podcast Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source SoundCloud Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube2 Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube Music Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Podcast Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:04 volumio volumio[17338]: info: [1767926764403] CoreMusicLibrary::Adding element Volusonic Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source SoundCloud Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube2 Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source YouTube Music Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Podcast Jan 08 20:46:04 volumio volumio[17338]: Cannot find translation for source Volusonic Jan 08 20:46:04 volumio volumio[17338]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 08 20:46:04 volumio volumio[17338]: info: Volumio Calling Home Jan 08 20:46:04 volumio volumio[17338]: info: [squeezelite_mc] Proxy server started on port 40693 Jan 08 20:46:04 volumio volumio[17338]: info: Preparing to generate the ALSA configuration file Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 20:46:04 volumio volumio[17338]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 08 20:46:04 volumio volumio[17338]: info: Reading ALSA contributions from plugins. Jan 08 20:46:04 volumio volumio[17338]: info: MPD Permissions set Jan 08 20:46:04 volumio volumio[17338]: info: MPD Permissions set Jan 08 20:46:04 volumio volumio[17338]: info: Upmpdcli Daemon Started Jan 08 20:46:04 volumio volumio[17338]: info: Spotify config file written Jan 08 20:46:04 volumio sudo[17696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 08 20:46:04 volumio sudo[17696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:04 volumio volumio[17338]: 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 08 20:46:04 volumio volumio[17338]: info: VolumeController:: Volume=100 Mute =false Jan 08 20:46:04 volumio volumio[17338]: info: CoreStateMachine::pushState Jan 08 20:46:04 volumio volumio[17338]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::volumioPushState Jan 08 20:46:04 volumio volumio[17338]: info: [squeezelite_mc] Server discovery started Jan 08 20:46:04 volumio volumio[17338]: info: [squeezelite_mc] Player finder started Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:04 volumio volumio[17338]: info: No need to fix Spotify hosts Jan 08 20:46:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:04 volumio go-librespot[17701]: go-librespot daemon starting... Jan 08 20:46:04 volumio sudo[17696]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:04 volumio go-librespot[17711]: time="2026-01-08T20:46:04-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:04 volumio go-librespot[17711]: time="2026-01-08T20:46:04-06:00" level=debug msg="app state loaded" Jan 08 20:46:04 volumio go-librespot[17711]: time="2026-01-08T20:46:04-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:04 volumio go-librespot[17711]: time="2026-01-08T20:46:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:05 volumio volumio[17338]: 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 08 20:46:05 volumio volumio[17338]: info: Volumio called home Jan 08 20:46:05 volumio volumio[17338]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 08 20:46:05 volumio volumio[17338]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 08 20:46:05 volumio volumio[17338]: 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 08 20:46:05 volumio volumio[17338]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 08 20:46:05 volumio volumio[17338]: SPOTIFY: BQBuHly8lLK6-wqZI9Mz3GDR8a_UfNWbifLqbvDWYcfin6lcYoCvbPOzGPtHuARdL6Xv22ECDilwpNTZ6MSpjPM4bKzYGmThUr6yCGVoqABDUcw8z-wggVocwENBynNNmh9BmCNSc11vl8jM2SSqe93FFuxiUfHHeY6IliFBJZtHokqsnP6aDSy_KgNsBl9cY10v1XMAbJ_kY_xvpFj8ADhx82PPATEbCtC5Et4 Jan 08 20:46:05 volumio volumio[17338]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 08 20:46:05 volumio volumio[17338]: info: New Spotify access token = BQBuHly8lLK6-wqZI9Mz3GDR8a_UfNWbifLqbvDWYcfin6lcYoCvbPOzGPtHuARdL6Xv22ECDilwpNTZ6MSpjPM4bKzYGmThUr6yCGVoqABDUcw8z-wggVocwENBynNNmh9BmCNSc11vl8jM2SSqe93FFuxiUfHHeY6IliFBJZtHokqsnP6aDSy_KgNsBl9cY10v1XMAbJ_kY_xvpFj8ADhx82PPATEbCtC5Et4 Jan 08 20:46:05 volumio volumio[17338]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 08 20:46:05 volumio go-librespot[17711]: time="2026-01-08T20:46:05-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:46:05 volumio go-librespot[17711]: time="2026-01-08T20:46:05-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 08 20:46:05 volumio go-librespot[17711]: time="2026-01-08T20:46:05-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 08 20:46:05 volumio go-librespot[17711]: time="2026-01-08T20:46:05-06:00" level=info msg="zeroconf server listening on port 34401" Jan 08 20:46:05 volumio volumio[17338]: info: Starting Shairport Sync Jan 08 20:46:05 volumio volumio[17338]: info: Starting Shairport Sync Jan 08 20:46:05 volumio volumio[17338]: info: Starting Shairport Sync Jan 08 20:46:05 volumio sudo[17720]: 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 08 20:46:05 volumio sudo[17720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:05 volumio sudo[17722]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:46:05 volumio sudo[17722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:05 volumio sudo[17720]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:05 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.30.210 Jan 08 20:46:05 volumio avahi-daemon[664]: Registering new address record for 169.254.30.210 on eth0.IPv4. Jan 08 20:46:05 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:46:05 volumio go-librespot[17711]: time="2026-01-08T20:46:05-06:00" level=debug msg="obtained new client token: AAB1tOntEUmWLrAfajgcbyZMSgqjre73GRVjpXgWmSFStR3kPr0CsQ4V8BldQT3gWhSP5thW0uzPejpP+xHTJ7Js1bmQMprrFvIZxb3l/30tGJP0CTZg3CMc+Y8+p9q66t47SB1eFvcFYgyrWBL/Tfr6gi3Lx0N5dOa2hnunAK30/yLyerKqmhUs15KVGpg7xMCwH5bkYE55+Nw0aLa7asUlNQhWlFUJO0te3VLP01Ha9fnqkKoIfyHtUQ==" Jan 08 20:46:05 volumio sudo[17724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:46:05 volumio sudo[17724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 20:46:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 20:46:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:46:05 volumio systemd[1]: shairport-sync.service: Consumed 2.244s CPU time. Jan 08 20:46:05 volumio sudo[17728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:46:05 volumio sudo[17728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:05 volumio go-librespot[17711]: time="2026-01-08T20:46:05-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 08 20:46:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:46:05 volumio volumio[17338]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 08 20:46:05 volumio go-librespot[17711]: time="2026-01-08T20:46:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Jan 08 20:46:05 volumio sudo[17722]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:05 volumio go-librespot[17711]: time="2026-01-08T20:46:05-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:05 volumio go-librespot[17711]: time="2026-01-08T20:46:05-06:00" level=debug msg="completed challenge" Jan 08 20:46:05 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:05 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:05 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:05 volumio sudo[17750]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 08 20:46:05 volumio sudo[17750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 20:46:05 volumio volumio[17338]: info: Asound.conf file unchanged, so no further update is needed Jan 08 20:46:05 volumio go-librespot[17711]: time="2026-01-08T20:46:05-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:46:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:05 volumio volumio[17338]: info: Output device has changed, restarting MPD Jan 08 20:46:05 volumio sudo[17750]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 20:46:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:46:05 volumio volumio[17338]: info: Output device has changed, restarting Shairport Sync Jan 08 20:46:05 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:05 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:05 volumio sudo[17767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 20:46:05 volumio sudo[17767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:05 volumio sudo[17767]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:05 volumio sudo[17769]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 20:46:05 volumio sudo[17769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:46:05 volumio sudo[17724]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:05 volumio volumio[17338]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:46:05 volumio sudo[17728]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:05 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 08 20:46:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 20:46:05 volumio systemd[1]: mpd.service: Consumed 1.766s CPU time. Jan 08 20:46:05 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 08 20:46:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 20:46:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 20:46:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 20:46:05 volumio volumio[17338]: info: Shairport-Sync Started Jan 08 20:46:05 volumio volumio[17338]: Error adding Membership: Error: addMembership EINVAL Jan 08 20:46:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 20:46:05 volumio volumio[17338]: info: MPD Permissions set Jan 08 20:46:05 volumio volumio[17338]: info: Shairport-Sync Started Jan 08 20:46:05 volumio volumio[17338]: info: Shairport-Sync Started Jan 08 20:46:05 volumio volumio[17338]: 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 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::volumioGetState Jan 08 20:46:06 volumio volumio[17338]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.30.210 Jan 08 20:46:06 volumio sudo[17798]: 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 08 20:46:06 volumio sudo[17798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:06 volumio sudo[17798]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:06 volumio volumio[17338]: info: Starting Shairport Sync Jan 08 20:46:06 volumio volumio[17338]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 08 20:46:06 volumio sudo[17806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:46:06 volumio sudo[17806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:06 volumio sudo[17795]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 08 20:46:06 volumio sudo[17795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 08 20:46:06 volumio volumio[17338]: 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 08 20:46:06 volumio sudo[17795]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:06 volumio volumio[17338]: info: Spotify Successfully logged in Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:06 volumio volumio[17338]: info: [1767926766226] CoreMusicLibrary::Adding element Spotify Jan 08 20:46:06 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:06 volumio volumio[17338]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:06 volumio volumio[17338]: Cannot find translation for source SoundCloud Jan 08 20:46:06 volumio volumio[17338]: Cannot find translation for source YouTube2 Jan 08 20:46:06 volumio volumio[17338]: Cannot find translation for source YouTube Music Jan 08 20:46:06 volumio volumio[17338]: Cannot find translation for source Podcast Jan 08 20:46:06 volumio volumio[17338]: Cannot find translation for source Volusonic Jan 08 20:46:06 volumio volumio[17338]: Cannot find translation for source Spotify Jan 08 20:46:06 volumio sudo[17808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 08 20:46:06 volumio sudo[17808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:06 volumio systemd[1]: Reloading. Jan 08 20:46:06 volumio kernel: hwmon hwmon1: Voltage normalised Jan 08 20:46:06 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.30.210 Jan 08 20:46:06 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.30.210 Jan 08 20:46:06 volumio avahi-daemon[664]: Withdrawing address record for 169.254.30.210 on eth0. Jan 08 20:46:06 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:06 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:07 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:07 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:07 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:07 volumio volumio[17338]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:46:08 volumio volumio[17338]: info: go-librespot daemon successfully initialized Jan 08 20:46:08 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 08 20:46:09 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 08 20:46:09 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 08 20:46:09 volumio sudo[17808]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Jan 08 20:46:09 volumio volumio[17338]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:46:09 volumio sudo[17862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:46:09 volumio sudo[17862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:09 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:09 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:09 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:09 volumio go-librespot[17864]: go-librespot daemon starting... Jan 08 20:46:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 20:46:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 20:46:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:46:09 volumio systemd[1]: shairport-sync.service: Consumed 1.385s CPU time. Jan 08 20:46:09 volumio go-librespot[17865]: time="2026-01-08T20:46:09-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:09 volumio go-librespot[17865]: time="2026-01-08T20:46:09-06:00" level=debug msg="app state loaded" Jan 08 20:46:09 volumio go-librespot[17865]: time="2026-01-08T20:46:09-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:09 volumio go-librespot[17865]: time="2026-01-08T20:46:09-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:46:10 volumio sudo[17806]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:10 volumio volumio[17338]: info: Shairport-Sync Started Jan 08 20:46:10 volumio sudo[17862]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:10 volumio volumio[17338]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 08 20:46:10 volumio sudo[17881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 08 20:46:10 volumio sudo[17881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:10 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 08 20:46:10 volumio go-librespot[17865]: time="2026-01-08T20:46:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:46:10 volumio go-librespot[17865]: time="2026-01-08T20:46:10-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 08 20:46:10 volumio go-librespot[17865]: time="2026-01-08T20:46:10-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 08 20:46:10 volumio go-librespot[17865]: time="2026-01-08T20:46:10-06:00" level=info msg="zeroconf server listening on port 35351" Jan 08 20:46:10 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 08 20:46:10 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 08 20:46:10 volumio sudo[17881]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:10 volumio go-librespot[17865]: time="2026-01-08T20:46:10-06:00" level=debug msg="obtained new client token: AACKHXFkeFRRg32EP45kgN8rWepGjFGIAi/wOBP+U+UsicERNMzMRt4lYNFW7PqnhhEt3FBbWj4h14BAbEgoF+4iHTPVXjynsfYodGs1JOtqL32hTGC+ooGARSVEkFgYIvej1ajxPWA3VA7FXnJCMbjHdcxgqAkEJaohCcJWmJpuMzcgRT985kqP/EbmrUuG/qcpp/s9mMv5J+xCGnvMrFTJ0qCM9JQyxdTdJsncKDE9RgLItjsnb5ksNA==" Jan 08 20:46:10 volumio go-librespot[17865]: time="2026-01-08T20:46:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:10 volumio go-librespot[17865]: time="2026-01-08T20:46:10-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:10 volumio go-librespot[17865]: time="2026-01-08T20:46:10-06:00" level=debug msg="completed challenge" Jan 08 20:46:10 volumio go-librespot[17865]: time="2026-01-08T20:46: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 08 20:46:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:10 volumio volumio[17338]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:46:10 volumio sudo[17892]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:46:10 volumio sudo[17892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:11 volumio sudo[17892]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:11 volumio volumio[17338]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 08 20:46:11 volumio sudo[17896]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 08 20:46:11 volumio sudo[17896]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:11 volumio sudo[17896]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:11 volumio volumio[17338]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 08 20:46:11 volumio sudo[17899]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 08 20:46:11 volumio sudo[17899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:11 volumio volumio[17338]: info: Initializing connection to go-librespot Websocket Jan 08 20:46:11 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.198.218 Jan 08 20:46:11 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:46:11 volumio avahi-daemon[664]: Registering new address record for 169.254.198.218 on eth0.IPv4. Jan 08 20:46:11 volumio volumio[17338]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 08 20:46:11 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 08 20:46:11 volumio mpd[17812]: 2026-01-08T20:46:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 08 20:46:11 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 08 20:46:11 volumio sudo[17899]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:11 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:11 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:11 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:11 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 08 20:46:11 volumio sudo[17769]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:11 volumio sudo[17661]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:11 volumio sudo[17651]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:11 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.198.218 Jan 08 20:46:11 volumio volumio[17338]: error: MPD error: The expression evaluated to a falsy value: Jan 08 20:46:11 volumio volumio[17338]: assert.ok(self.idling) Jan 08 20:46:11 volumio volumio[17338]: error: The expression evaluated to a falsy value: Jan 08 20:46:11 volumio volumio[17338]: assert.ok(self.idling) Jan 08 20:46:11 volumio volumio[17338]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:46:11 volumio volumio[17338]: error: MPD error: The expression evaluated to a falsy value: Jan 08 20:46:11 volumio volumio[17338]: assert.ok(self.idling) Jan 08 20:46:11 volumio volumio[17338]: error: The expression evaluated to a falsy value: Jan 08 20:46:11 volumio volumio[17338]: assert.ok(self.idling) Jan 08 20:46:11 volumio volumio[17338]: info: MPD running with PID17812 Jan 08 20:46:11 volumio volumio[17338]: ,establishing connection Jan 08 20:46:11 volumio volumio[17338]: error: updateQueue error: null Jan 08 20:46:11 volumio volumio[17338]: error: updateQueue error: null Jan 08 20:46:11 volumio sudo[17926]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:46:11 volumio sudo[17926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:12 volumio sudo[17926]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:12 volumio ntpd[872]: IO: Listen normally on 9910 eth0 169.254.198.218:123 Jan 08 20:46:12 volumio ntpd[872]: IO: new interface(s) found: waking up resolver Jan 08 20:46:12 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.198.218 Jan 08 20:46:12 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.198.218 Jan 08 20:46:12 volumio avahi-daemon[664]: Withdrawing address record for 169.254.198.218 on eth0. Jan 08 20:46:12 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:12 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:12 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:12 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:12 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:12 volumio volumio[17338]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:46:12 volumio sudo[17948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:46:12 volumio sudo[17948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:12 volumio sudo[17948]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:13 volumio volumio[17338]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:46:13 volumio sudo[17951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:46:13 volumio sudo[17951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:13 volumio sudo[17951]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Jan 08 20:46:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:13 volumio go-librespot[17953]: go-librespot daemon starting... Jan 08 20:46:13 volumio go-librespot[17954]: time="2026-01-08T20:46:13-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:13 volumio go-librespot[17954]: time="2026-01-08T20:46:13-06:00" level=debug msg="app state loaded" Jan 08 20:46:13 volumio go-librespot[17954]: time="2026-01-08T20:46:13-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:13 volumio go-librespot[17954]: time="2026-01-08T20:46:13-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:13 volumio volumio[17338]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:46:13 volumio sudo[17961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:46:13 volumio sudo[17961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:14 volumio sudo[17961]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:14 volumio volumio[17338]: info: Initializing connection to go-librespot Websocket Jan 08 20:46:14 volumio go-librespot[17954]: time="2026-01-08T20:46: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 08 20:46:14 volumio go-librespot[17954]: time="2026-01-08T20:46: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 08 20:46:14 volumio go-librespot[17954]: time="2026-01-08T20:46:14-06:00" level=debug msg="new websocket client" Jan 08 20:46:14 volumio go-librespot[17954]: time="2026-01-08T20:46: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 08 20:46:14 volumio volumio[17338]: info: Connection to go-librespot Websocket established Jan 08 20:46:14 volumio go-librespot[17954]: time="2026-01-08T20:46:14-06:00" level=info msg="zeroconf server listening on port 38785" Jan 08 20:46:14 volumio ntpd[872]: IO: Deleting interface #9910 eth0, 169.254.198.218#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Jan 08 20:46:14 volumio go-librespot[17954]: time="2026-01-08T20:46:14-06:00" level=debug msg="obtained new client token: AAB07qfvCKQtHUIy4A/K+pqO4z+pcDgXO4+mlciVfqMXjemPHpc3fYh4mlX5DP9bO/QiwXfOAjGzwtX9aW0G2CYi11cTqXAWryf1Z965+ltJz/zDjW0CspXRpHb1/2qYxBzLXlR+UKIH/vjv0S7IsHOXOjv9CBouqAEwygCSOMJat/hBO2MgWfSxLB7poaOvFaxZm7lc/ZKjbN2oY7pZ2prSWXwaOFY/tLdM4t/BhmllPAZ3eyLs2+CPTg==" Jan 08 20:46:14 volumio go-librespot[17954]: time="2026-01-08T20:46:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:14 volumio go-librespot[17954]: time="2026-01-08T20:46:14-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:14 volumio go-librespot[17954]: time="2026-01-08T20:46:14-06:00" level=debug msg="completed challenge" Jan 08 20:46:14 volumio go-librespot[17954]: time="2026-01-08T20:46: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 08 20:46:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:14 volumio volumio[17338]: info: Connection to go-librespot Websocket closed Jan 08 20:46:14 volumio volumio[17338]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:46:14 volumio sudo[17965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:46:14 volumio sudo[17965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:14 volumio sudo[17965]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:14 volumio volumio[17338]: info: Completed starting Core Plugins Jan 08 20:46:14 volumio volumio[17338]: info: ------------------------------------------- Jan 08 20:46:14 volumio volumio[17338]: info: ----- MyVolumio plugins startup ---- Jan 08 20:46:14 volumio volumio[17338]: info: ------------------------------------------- Jan 08 20:46:14 volumio volumio[17338]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 08 20:46:14 volumio sudo[17969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 20:46:14 volumio sudo[17969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:14 volumio sudo[17971]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 20:46:14 volumio sudo[17971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:14 volumio sudo[17974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 20:46:14 volumio sudo[17974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:14 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 08 20:46:14 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 08 20:46:14 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 08 20:46:14 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 08 20:46:14 volumio sudo[17974]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:14 volumio sudo[17971]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:14 volumio sudo[17969]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:14 volumio mpd_monitor.sh[17977]: MPD Monitor Service: Starting MPD Monitor Service Jan 08 20:46:14 volumio volumio[17338]: info: Successfully started MPD Monitor Jan 08 20:46:14 volumio volumio[17338]: info: Successfully started MPD Monitor Jan 08 20:46:14 volumio volumio[17338]: info: Successfully started MPD Monitor Jan 08 20:46:16 volumio kernel: hwmon hwmon1: Voltage normalised Jan 08 20:46:17 volumio volumio[17338]: info: Getting Spotify volume Jan 08 20:46:17 volumio volumio[17338]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 20:46:17 volumio volumio[17338]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 08 20:46:17 volumio volumio[17338]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 08 20:46:17 volumio volumio[17338]: errno: -111, Jan 08 20:46:17 volumio volumio[17338]: code: 'ECONNREFUSED', Jan 08 20:46:17 volumio volumio[17338]: syscall: 'connect', Jan 08 20:46:17 volumio volumio[17338]: address: '127.0.0.1', Jan 08 20:46:17 volumio volumio[17338]: port: 9879, Jan 08 20:46:17 volumio volumio[17338]: response: undefined Jan 08 20:46:17 volumio volumio[17338]: } Jan 08 20:46:17 volumio volumio[17338]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 20:46:17 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.250.224 Jan 08 20:46:17 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:46:17 volumio avahi-daemon[664]: Registering new address record for 169.254.250.224 on eth0.IPv4. Jan 08 20:46:17 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:17 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:17 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:17 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.250.224 Jan 08 20:46:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Jan 08 20:46:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:17 volumio go-librespot[18024]: go-librespot daemon starting... Jan 08 20:46:17 volumio go-librespot[18025]: time="2026-01-08T20:46:17-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:17 volumio go-librespot[18025]: time="2026-01-08T20:46:17-06:00" level=debug msg="app state loaded" Jan 08 20:46:17 volumio go-librespot[18025]: time="2026-01-08T20:46:17-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:17 volumio go-librespot[18025]: time="2026-01-08T20:46:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:18 volumio go-librespot[18025]: time="2026-01-08T20:46: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:46:18 volumio go-librespot[18025]: time="2026-01-08T20:46:18-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 08 20:46:18 volumio go-librespot[18025]: time="2026-01-08T20:46:18-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 08 20:46:18 volumio go-librespot[18025]: time="2026-01-08T20:46:18-06:00" level=info msg="zeroconf server listening on port 40077" Jan 08 20:46:18 volumio go-librespot[18025]: time="2026-01-08T20:46:18-06:00" level=debug msg="obtained new client token: AAD2E12fvsoVRv0+joyx12YJ8WfF7cfK/EdQt6r8FZyz5uhxuR6pRLJbigOqxlmfgb+dqpQdBWB5rptrbDBN89fOhy5K6mlxg0atm2eVWkC2+Kp2mWv7FVMQVyvZ4TS8nZfWM6lwhq1EwxsdO80g93bh1gRT3XfI46+dA1KV/IfXMIioss0a4A5bU3nxaEMCXnYgHQPgHW8O7MGqL2rV8YX7yFay0Pa78WiTReoD2U4c3rH+hsGzQk0=" Jan 08 20:46:18 volumio go-librespot[18025]: time="2026-01-08T20:46:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:18 volumio sudo[18034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-08 20:45' Jan 08 20:46:18 volumio sudo[18034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:18 volumio go-librespot[18025]: time="2026-01-08T20:46:18-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:18 volumio go-librespot[18025]: time="2026-01-08T20:46:18-06:00" level=debug msg="completed challenge" Jan 08 20:46:18 volumio go-librespot[18025]: time="2026-01-08T20:46: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 08 20:46:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:18 volumio sudo[18034]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:18 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.250.224 Jan 08 20:46:18 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.250.224 Jan 08 20:46:18 volumio avahi-daemon[664]: Withdrawing address record for 169.254.250.224 on eth0. Jan 08 20:46:18 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:18 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:18 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:18 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:18 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:18 volumio volumio-remote-updater[14193]: [2026-01-08 20:46:18] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 08 20:46:18 volumio volumio-remote-updater[14193]: [2026-01-08 20:46:18] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 08 20:46:18 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:18 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 08 20:46:18 volumio systemd[1]: volumio.service: Consumed 46.450s CPU time. Jan 08 20:46:18 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 08 20:46:18 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 08 20:46:18 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 15454. Jan 08 20:46:18 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 08 20:46:18 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 08 20:46:18 volumio systemd[1]: volumio.service: Consumed 46.450s CPU time. Jan 08 20:46:18 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 08 20:46:19 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 08 20:46:20 volumio volumio[18062]: info: ------------------------------------------- Jan 08 20:46:20 volumio volumio[18062]: info: ----- Volumio3 ---- Jan 08 20:46:20 volumio volumio[18062]: info: ------------------------------------------- Jan 08 20:46:20 volumio volumio[18062]: info: ----- System startup ---- Jan 08 20:46:20 volumio volumio[18062]: info: ------------------------------------------- Jan 08 20:46:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Jan 08 20:46:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:21 volumio go-librespot[18083]: go-librespot daemon starting... Jan 08 20:46:21 volumio go-librespot[18084]: time="2026-01-08T20:46:21-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:21 volumio go-librespot[18084]: time="2026-01-08T20:46:21-06:00" level=debug msg="app state loaded" Jan 08 20:46:21 volumio go-librespot[18084]: time="2026-01-08T20:46:21-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:21 volumio go-librespot[18084]: time="2026-01-08T20:46:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:21 volumio volumio[18062]: info: MYVOLUMIO Environment detected Jan 08 20:46:22 volumio go-librespot[18084]: time="2026-01-08T20:46:22-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:46:22 volumio go-librespot[18084]: time="2026-01-08T20:46:22-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 08 20:46:22 volumio go-librespot[18084]: time="2026-01-08T20:46:22-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 08 20:46:22 volumio go-librespot[18084]: time="2026-01-08T20:46:22-06:00" level=info msg="zeroconf server listening on port 42945" Jan 08 20:46:22 volumio volumio[18062]: info: Plugin folders cleanup Jan 08 20:46:22 volumio volumio[18062]: info: Scanning into folder /volumio/app/plugins/ Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category audio_interface Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category miscellanea Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category music_service Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category plugins.json Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category system_controller Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category user_interface Jan 08 20:46:22 volumio volumio[18062]: info: Scanning into folder /data/plugins/ Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category audio_interface Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category music_service Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category system_controller Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category system_hardware Jan 08 20:46:22 volumio volumio[18062]: info: Scanning category user_interface Jan 08 20:46:22 volumio volumio[18062]: info: Plugin folders cleanup completed Jan 08 20:46:22 volumio volumio[18062]: info: ------------------------------------------- Jan 08 20:46:22 volumio volumio[18062]: info: ----- Core plugins startup ---- Jan 08 20:46:22 volumio volumio[18062]: info: ------------------------------------------- Jan 08 20:46:22 volumio volumio[18062]: info: Loading plugins from folder /volumio/app/plugins/ Jan 08 20:46:22 volumio volumio[18062]: info: Adding plugin upnp to MyMusic Plugins Jan 08 20:46:22 volumio volumio[18062]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 08 20:46:22 volumio volumio[18062]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 08 20:46:22 volumio volumio[18062]: info: Loading plugins from folder /data/plugins/ Jan 08 20:46:22 volumio go-librespot[18084]: time="2026-01-08T20:46:22-06:00" level=debug msg="obtained new client token: AAAN72teRSXYuKeVqJTLBsGaJfd3GR5HidGv8c4OINNkpUSo0sEndKQxnjtevw1++hfNGV/9IyPAhI9i1jYAOOfXbz/6UgVhQRuS2ly/dxce2kB9v5e4T2kOyE40mtjRqBy57TLrH50tXqDwn0+KbxzT93i6mBHgn0HKLALna6C974bbNZEF3QJKGRYdOWdvqyR757wOqQz6V6ucY59cOSgxOyw0dJuZpp8hNlIPOAVo/6Nvq7Qp2DI=" Jan 08 20:46:22 volumio volumio[18062]: info: Loading plugin "system"... Jan 08 20:46:22 volumio go-librespot[18084]: time="2026-01-08T20:46:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:22 volumio volumio[18062]: info: Loading plugin "appearance"... Jan 08 20:46:22 volumio go-librespot[18084]: time="2026-01-08T20:46:22-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:22 volumio go-librespot[18084]: time="2026-01-08T20:46:22-06:00" level=debug msg="completed challenge" Jan 08 20:46:22 volumio go-librespot[18084]: time="2026-01-08T20:46: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 08 20:46:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:23 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 08 20:46:23 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.224.159 Jan 08 20:46:23 volumio avahi-daemon[664]: Registering new address record for 169.254.224.159 on eth0.IPv4. Jan 08 20:46:23 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:46:23 volumio volumio-remote-updater[14193]: [2026-01-08 20:46:23] [connect] Successful connection Jan 08 20:46:23 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:23 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:23 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:23 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.224.159 Jan 08 20:46:23 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.224.159 Jan 08 20:46:23 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.224.159 Jan 08 20:46:23 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:23 volumio avahi-daemon[664]: Withdrawing address record for 169.254.224.159 on eth0. Jan 08 20:46:23 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:23 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:23 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:23 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:24 volumio volumio[18062]: info: Loading plugin "network"... Jan 08 20:46:24 volumio volumio[18062]: info: Refreshing Cached IP Addresses Jan 08 20:46:24 volumio sudo[18131]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 20:46:24 volumio sudo[18131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:24 volumio sudo[18133]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 20:46:24 volumio sudo[18133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:24 volumio volumio[18062]: info: Loading plugin "services"... Jan 08 20:46:24 volumio sudo[18133]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:24 volumio sudo[18131]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:24 volumio volumio[18062]: info: Loading plugin "alsa_controller"... Jan 08 20:46:24 volumio sudo[18140]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 08 20:46:24 volumio sudo[18140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:24 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 20:46:24 volumio volumio[18062]: info: Loading plugin "wizard"... Jan 08 20:46:24 volumio volumio[18062]: info: Loading plugin "networkfs"... Jan 08 20:46:24 volumio volumio[18062]: info: Starting Udev Watcher for removable devices Jan 08 20:46:24 volumio volumio[18062]: info: Ignoring mount for partition: boot Jan 08 20:46:24 volumio volumio[18062]: info: Ignoring mount for partition: volumio Jan 08 20:46:24 volumio volumio[18062]: info: Ignoring mount for partition: volumio_data Jan 08 20:46:24 volumio volumio[18062]: info: Mounting Device Wikipedia Jan 08 20:46:24 volumio sudo[18170]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 08 20:46:24 volumio sudo[18170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:24 volumio sudo[18170]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:24 volumio volumio[18062]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 08 20:46:24 volumio volumio[18062]: dmesg(1) may have more information after failed mount system call. Jan 08 20:46:24 volumio volumio[18062]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 08 20:46:24 volumio volumio[18062]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 08 20:46:24 volumio volumio[18062]: dmesg(1) may have more information after failed mount system call. Jan 08 20:46:24 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 20:46:24 volumio volumio[18062]: info: Loading plugin "volumio_command_line_client"... Jan 08 20:46:24 volumio volumio[18062]: info: Loading plugin "upnp"... Jan 08 20:46:24 volumio volumio[18062]: info: [1767926784685] Starting Upmpd Daemon Jan 08 20:46:24 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 20:46:24 volumio volumio[18062]: info: Loading plugin "my_music"... Jan 08 20:46:24 volumio volumio[18062]: info: Loading plugin "mpd"... Jan 08 20:46:24 volumio sudo[18140]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:25 volumio volumio[18062]: info: Loading plugin "upnp_browser"... Jan 08 20:46:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Jan 08 20:46:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:25 volumio go-librespot[18172]: go-librespot daemon starting... Jan 08 20:46:25 volumio go-librespot[18173]: time="2026-01-08T20:46:25-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:25 volumio go-librespot[18173]: time="2026-01-08T20:46:25-06:00" level=debug msg="app state loaded" Jan 08 20:46:25 volumio go-librespot[18173]: time="2026-01-08T20:46:25-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:25 volumio go-librespot[18173]: time="2026-01-08T20:46:25-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:25 volumio go-librespot[18173]: time="2026-01-08T20:46:25-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 08 20:46:25 volumio go-librespot[18173]: time="2026-01-08T20:46:25-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 08 20:46:25 volumio go-librespot[18173]: time="2026-01-08T20:46:25-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 08 20:46:25 volumio go-librespot[18173]: time="2026-01-08T20:46:25-06:00" level=info msg="zeroconf server listening on port 33959" Jan 08 20:46:26 volumio go-librespot[18173]: time="2026-01-08T20:46:26-06:00" level=debug msg="obtained new client token: AAAhVJrTIJnh0JGS9jL5cBfYo4LWp0rUp9VIjjY4nSCRJ283zbjX3iTgPRfJ+MKdNY2hVS+ZBNeUWsyzy7b57tQxdrWEXE3Bwtq0g+BaFORpl9erKxaLKA0oy4RHT0L4NJE3IQeKM9ELb4VG3ifSZIV7toVfLGVY4mrU7fxMaXaR6TU7l6ahHlV/VE557uX3eLoZSfeTh3jsWvuVEo2LQ1eT3AuY5Pp7EJMswVd/VdeykLCAdAT7xqA=" Jan 08 20:46:26 volumio go-librespot[18173]: time="2026-01-08T20:46:26-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:26 volumio go-librespot[18173]: time="2026-01-08T20:46:26-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:26 volumio go-librespot[18173]: time="2026-01-08T20:46:26-06:00" level=debug msg="completed challenge" Jan 08 20:46:26 volumio go-librespot[18173]: time="2026-01-08T20:46:26-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 08 20:46:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:27 volumio volumio[18062]: info: Loading plugin "alarm-clock"... Jan 08 20:46:28 volumio volumio[18062]: info: Loading plugin "airplay_emulation"... Jan 08 20:46:28 volumio volumio[18062]: info: Starting Shairport Sync Jan 08 20:46:28 volumio volumio[18062]: info: Loading plugin "last_100"... Jan 08 20:46:28 volumio volumio[18062]: info: Loading plugin "webradio"... Jan 08 20:46:28 volumio volumio[18062]: info: Loading plugin "i2s_dacs"... Jan 08 20:46:28 volumio volumio[18062]: info: I2S DAC not set, start Auto-detection Jan 08 20:46:28 volumio volumio[18062]: info: Loading plugin "volumiodiscovery"... Jan 08 20:46:28 volumio volumio[18062]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 20:46:28 volumio node[18062]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 20:46:28 volumio volumio[18062]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 20:46:28 volumio volumio[18062]: *** WARNING *** For more information see Jan 08 20:46:28 volumio volumio[18062]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 20:46:28 volumio volumio[18062]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 20:46:28 volumio volumio[18062]: *** WARNING *** For more information see Jan 08 20:46:28 volumio node[18062]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 20:46:28 volumio node[18062]: *** WARNING *** For more information see Jan 08 20:46:28 volumio node[18062]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 20:46:28 volumio node[18062]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 20:46:28 volumio node[18062]: *** WARNING *** For more information see Jan 08 20:46:28 volumio volumio[18062]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 08 20:46:28 volumio volumio[18062]: info: Discovery: Started advertising with name: Volumio Jan 08 20:46:28 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 20:46:28 volumio volumio[18062]: info: Loading plugin "bandcamp"... Jan 08 20:46:29 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.76.99 Jan 08 20:46:29 volumio avahi-daemon[664]: Registering new address record for 169.254.76.99 on eth0.IPv4. Jan 08 20:46:29 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:46:29 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:29 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:29 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Jan 08 20:46:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:29 volumio go-librespot[18199]: go-librespot daemon starting... Jan 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-06:00" level=debug msg="app state loaded" Jan 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:29 volumio volumio[18062]: info: Plugin calmradio is not enabled Jan 08 20:46:29 volumio volumio[18062]: info: Loading plugin "soundcloud"... Jan 08 20:46:29 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.76.99 Jan 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-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 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-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 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-06:00" level=info msg="zeroconf server listening on port 45381" Jan 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-06:00" level=debug msg="obtained new client token: AADQFLXxO610F/xuSQCn07zjlbPQk1mcZ5yHUolqkvdZ31Ttziq17ul9iEAMgdixNBE6StzpysyT0DoCIc0gNd8EzSv6k8f6UPU2DT5qr14uJDtHmGcEdAfpXTlCeHh+iyTgCcTh24PnpGKiCEKBKkdKj/bYadtcffJaGbAjca03PyLIbeWJqwmchtzPNUzpIYiKfe05foyCPDsW4MhJFXtPn0mP9xmIcU5R1QeePZEkVzoVxqPAgI5qhQ==" Jan 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:29 volumio go-librespot[18200]: time="2026-01-08T20:46:29-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:30 volumio go-librespot[18200]: time="2026-01-08T20:46:30-06:00" level=debug msg="completed challenge" Jan 08 20:46:30 volumio volumio[18062]: info: Loading plugin "spop"... Jan 08 20:46:30 volumio go-librespot[18200]: time="2026-01-08T20:46:30-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:46:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:30 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.76.99 Jan 08 20:46:30 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.76.99 Jan 08 20:46:30 volumio avahi-daemon[664]: Withdrawing address record for 169.254.76.99 on eth0. Jan 08 20:46:30 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:30 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:30 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:30 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:30 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:31 volumio volumio[18062]: info: Loading plugin "squeezelite_mc"... Jan 08 20:46:31 volumio kernel: hwmon hwmon1: Voltage normalised Jan 08 20:46:31 volumio volumio[18062]: info: Loading plugin "youtube2"... Jan 08 20:46:32 volumio volumio[18062]: info: Loading plugin "ytcr"... Jan 08 20:46:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Jan 08 20:46:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:33 volumio go-librespot[18224]: go-librespot daemon starting... Jan 08 20:46:33 volumio go-librespot[18225]: time="2026-01-08T20:46:33-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:33 volumio go-librespot[18225]: time="2026-01-08T20:46:33-06:00" level=debug msg="app state loaded" Jan 08 20:46:33 volumio go-librespot[18225]: time="2026-01-08T20:46:33-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:33 volumio go-librespot[18225]: time="2026-01-08T20:46:33-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:33 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 08 20:46:33 volumio go-librespot[18225]: time="2026-01-08T20:46:33-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 08 20:46:33 volumio go-librespot[18225]: time="2026-01-08T20:46:33-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 08 20:46:33 volumio go-librespot[18225]: time="2026-01-08T20:46:33-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 08 20:46:33 volumio go-librespot[18225]: time="2026-01-08T20:46:33-06:00" level=info msg="zeroconf server listening on port 44473" Jan 08 20:46:33 volumio go-librespot[18225]: time="2026-01-08T20:46:33-06:00" level=debug msg="obtained new client token: AAAP81alDpDyYCRa6I10G9nh0aE/2jS2xF6iR0ms5ANI7hIunzZJXuVyS2o/tR2xDLrRv2aGOzIWy//Ee+XqyBrz4iYIAO4Vk/1HYgXThb/T02S9OUCuOTqM0s89uVgIVu2fYrM6NLOqlR2QY1dDe57KmFvc2PdQUj+smWTaZc1wfMEc2Y9PcfF+T/Ol5V6svuLemMuc8lw3ewHbnLHZD1Q5WZdBjHhyYTwcr9LLs6GVJOsgeUUa7EJ5BQ==" Jan 08 20:46:33 volumio go-librespot[18225]: time="2026-01-08T20:46:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:34 volumio go-librespot[18225]: time="2026-01-08T20:46:34-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:34 volumio go-librespot[18225]: time="2026-01-08T20:46:34-06:00" level=debug msg="completed challenge" Jan 08 20:46:34 volumio go-librespot[18225]: time="2026-01-08T20:46:34-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:46:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:34 volumio volumio[18062]: info: Loading plugin "ytmusic"... Jan 08 20:46:35 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.138.154 Jan 08 20:46:35 volumio avahi-daemon[664]: Registering new address record for 169.254.138.154 on eth0.IPv4. Jan 08 20:46:35 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:46:35 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:35 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:35 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:35 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.138.154 Jan 08 20:46:35 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.138.154 Jan 08 20:46:35 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.138.154 Jan 08 20:46:35 volumio avahi-daemon[664]: Withdrawing address record for 169.254.138.154 on eth0. Jan 08 20:46:35 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:35 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:35 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:35 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:35 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:35 volumio volumio[18062]: info: Plugin now_playing is not enabled Jan 08 20:46:35 volumio volumio[18062]: info: Loading plugin "outputs"... Jan 08 20:46:35 volumio volumio[18062]: info: Loading plugin "albumart"... Jan 08 20:46:35 volumio volumio[18062]: info: Plugin example_plugin is not enabled Jan 08 20:46:35 volumio volumio[18062]: info: Loading plugin "inputs"... Jan 08 20:46:35 volumio volumio[18062]: info: Loading plugin "updater_comm"... Jan 08 20:46:35 volumio volumio[18062]: info: Plugin mpdemulation is not enabled Jan 08 20:46:35 volumio volumio[18062]: info: Loading plugin "rest_api"... Jan 08 20:46:35 volumio volumio[18062]: info: Loading plugin "websocket"... Jan 08 20:46:35 volumio volumio[18062]: info: Starting Socket.io Server version 1.7.4 Jan 08 20:46:35 volumio volumio[18062]: info: Plugin fusiondsp is not enabled Jan 08 20:46:35 volumio volumio[18062]: info: Plugin mpdoutput is not enabled Jan 08 20:46:35 volumio volumio[18062]: info: Plugin RoonBridge is not enabled Jan 08 20:46:35 volumio volumio[18062]: info: Loading plugin "podcast"... Jan 08 20:46:36 volumio volumio-remote-updater[14193]: [2026-01-08 20:46:36] [connect] Successful connection Jan 08 20:46:36 volumio volumio[18062]: info: ControllerPodcast::constructor Jan 08 20:46:36 volumio volumio[18062]: info: Loading plugin "volusonic"... Jan 08 20:46:36 volumio volumio[18282]: Forking 3 albumart workers Jan 08 20:46:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Jan 08 20:46:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:37 volumio go-librespot[18322]: go-librespot daemon starting... Jan 08 20:46:37 volumio go-librespot[18323]: time="2026-01-08T20:46:37-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:37 volumio go-librespot[18323]: time="2026-01-08T20:46:37-06:00" level=debug msg="app state loaded" Jan 08 20:46:37 volumio go-librespot[18323]: time="2026-01-08T20:46:37-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:37 volumio go-librespot[18323]: time="2026-01-08T20:46:37-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:38 volumio go-librespot[18323]: time="2026-01-08T20:46:38-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:46:38 volumio go-librespot[18323]: time="2026-01-08T20:46:38-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 08 20:46:38 volumio go-librespot[18323]: time="2026-01-08T20:46:38-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 08 20:46:38 volumio go-librespot[18323]: time="2026-01-08T20:46:38-06:00" level=info msg="zeroconf server listening on port 36459" Jan 08 20:46:38 volumio go-librespot[18323]: time="2026-01-08T20:46:38-06:00" level=debug msg="obtained new client token: AAA6tmoONbqVxIfQjhT8vrQpl+8/THs9nA9lBE04/3dzvueEO06N+VuZye4HbD/6AA0AEAF3JI5FyqkMeyTOjOtvZqq2UHaJOu+CzkO2C+/Eh9+b/ROqXH+yMgTfm9A5Oy1iybaOXJs8XOt9ain7shBYU4w1s6CqUCYcQowWMUNWUloJikhABeso95SZ7RYAYp6mj22zoj8GG1JZB62szHoQm4R7TmK1fuod1fLxlVoiLRC4FZQN5HE=" Jan 08 20:46:38 volumio go-librespot[18323]: time="2026-01-08T20:46:38-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:38 volumio go-librespot[18323]: time="2026-01-08T20:46:38-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:38 volumio go-librespot[18323]: time="2026-01-08T20:46:38-06:00" level=debug msg="completed challenge" Jan 08 20:46:38 volumio go-librespot[18323]: time="2026-01-08T20:46:38-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:46:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:38 volumio volumio[18062]: info: Applying required configuration parameters for plugin volusonic Jan 08 20:46:38 volumio volumio[18062]: info: Loading plugin "backup_restore"... Jan 08 20:46:38 volumio volumio[18292]: Starting albumart workers Jan 08 20:46:38 volumio volumio[18294]: Starting albumart workers Jan 08 20:46:39 volumio volumio[18293]: Starting albumart workers Jan 08 20:46:39 volumio volumio[18062]: info: Applying required configuration parameters for plugin backup_restore Jan 08 20:46:39 volumio volumio[18062]: info: Plugin rpi_eeprom_config is not enabled Jan 08 20:46:39 volumio volumio[18062]: info: Plugin rpi_eeprom_updater is not enabled Jan 08 20:46:39 volumio volumio[18062]: info: Loading plugin "scheduledrestart"... Jan 08 20:46:39 volumio volumio[18062]: info: Applying required configuration parameters for plugin scheduledrestart Jan 08 20:46:39 volumio volumio[18062]: info: Plugin Bluetoothremote is not enabled Jan 08 20:46:39 volumio volumio[18062]: info: Plugin music_services_shield is not enabled Jan 08 20:46:39 volumio volumio[18062]: info: Loading plugin "Systeminfo"... Jan 08 20:46:40 volumio volumio[18062]: info: Plugin peppymeterbasic is not enabled Jan 08 20:46:40 volumio volumio[18062]: info: Loading plugin "peppyspectrum"... Jan 08 20:46:40 volumio volumio[18062]: info: Loading i18n strings for locale en Jan 08 20:46:40 volumio volumio[18062]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 08 20:46:40 volumio volumio[18062]: Updating browse sources language Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:40 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.178.207 Jan 08 20:46:40 volumio avahi-daemon[664]: Registering new address record for 169.254.178.207 on eth0.IPv4. Jan 08 20:46:40 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::initPlayerControls Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:46:40 volumio volumio[18062]: Express server listening on port 3000 Jan 08 20:46:40 volumio volumio[18062]: [Metrics] WebUI: 20s 393.42ms Jan 08 20:46:40 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:40 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:40 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:40 volumio volumio[18062]: info: CoreStateMachine::resetVolumioState Jan 08 20:46:40 volumio volumio[18062]: info: CoreStateMachine::getcurrentVolume Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 20:46:40 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:40 volumio sudo[18370]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 20:46:40 volumio sudo[18370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:40 volumio sudo[18370]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:40 volumio sudo[18372]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 20:46:40 volumio sudo[18372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:40 volumio sudo[18372]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:40 volumio volumio[18062]: info: Volumio Network Manager: Network status updated: 1 Jan 08 20:46:41 volumio volumio[18062]: info: VolumeController:: Volume=100 Mute =false Jan 08 20:46:41 volumio volumio[18062]: info: CoreStateMachine::pushState Jan 08 20:46:41 volumio volumio[18062]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioPushState Jan 08 20:46:41 volumio volumio[18062]: info: CoreStateMachine::updateTrackBlock Jan 08 20:46:41 volumio volumio[18062]: info: CorePlayQueue::getTrackBlock Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 20:46:41 volumio volumio[18062]: info: Reloading queue from file Jan 08 20:46:41 volumio volumio[18062]: info: CoreStateMachine::setRepeat null single undefined Jan 08 20:46:41 volumio volumio[18062]: info: CoreStateMachine::pushState Jan 08 20:46:41 volumio volumio[18062]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioPushState Jan 08 20:46:41 volumio volumio[18062]: info: CoreStateMachine::setRandom null Jan 08 20:46:41 volumio volumio[18062]: info: CoreStateMachine::pushState Jan 08 20:46:41 volumio volumio[18062]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioPushState Jan 08 20:46:41 volumio volumio[18062]: info: Setting Device type: Raspberry PI Jan 08 20:46:41 volumio volumio[18062]: info: VolumeController:: Volume=100 Mute =false Jan 08 20:46:41 volumio volumio[18062]: info: CoreStateMachine::pushState Jan 08 20:46:41 volumio volumio[18062]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioPushState Jan 08 20:46:41 volumio volumio[18062]: info: Completed loading Core Plugins Jan 08 20:46:41 volumio volumio[18062]: info: Preparing to generate the ALSA configuration file Jan 08 20:46:41 volumio sudo[18385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 08 20:46:41 volumio sudo[18385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:41 volumio volumio[18062]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 08 20:46:41 volumio volumio[18062]: info: Discovery: Found device Volumio Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioGetState Jan 08 20:46:41 volumio volumio[18062]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:41 volumio volumio[18062]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 08 20:46:41 volumio volumio[18062]: info: Reading ALSA contributions from plugins. Jan 08 20:46:41 volumio volumio[18062]: info: Asound.conf file unchanged, so no further update is needed Jan 08 20:46:41 volumio volumio[18062]: info: Output device has changed, restarting MPD Jan 08 20:46:41 volumio sudo[18385]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:41 volumio volumio[18062]: info: Output device has changed, restarting Shairport Sync Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:41 volumio sudo[18388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 20:46:41 volumio sudo[18388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:41 volumio sudo[18388]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:41 volumio sudo[18390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 20:46:41 volumio sudo[18390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:41 volumio volumio[18062]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:46:41 volumio volumio[18062]: info: ___________ START PLUGINS ___________ Jan 08 20:46:41 volumio volumio[18062]: info: ControllerMpd::onStart: Initializing MPD Jan 08 20:46:41 volumio volumio[18062]: info: Creating MPD Configuration file Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:41 volumio volumio[18062]: info: [1767926801357] CoreMusicLibrary::Adding element Media Servers Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 08 20:46:41 volumio sudo[18398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 20:46:41 volumio sudo[18398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:41 volumio sudo[18398]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:41 volumio sudo[18400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 20:46:41 volumio sudo[18400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:41 volumio volumio[18062]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:41 volumio volumio[18062]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:41 volumio volumio[18062]: info: [1767926801473] CoreMusicLibrary::Adding element Last_100 Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:41 volumio volumio[18062]: info: [1767926801478] CoreMusicLibrary::Adding element Webradio Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:41 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 08 20:46:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 20:46:41 volumio systemd[1]: mpd.service: Consumed 5.906s CPU time. Jan 08 20:46:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 20:46:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 20:46:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 20:46:41 volumio volumio[18062]: info: Initializing BBC Radios Jan 08 20:46:41 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.178.207 Jan 08 20:46:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:41 volumio volumio[18062]: info: [1767926801580] CoreMusicLibrary::Adding element Bandcamp Discover Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:41 volumio volumio[18062]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:41 volumio volumio[18062]: info: [1767926801602] CoreMusicLibrary::Adding element SoundCloud Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:41 volumio volumio[18062]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:41 volumio volumio[18062]: Cannot find translation for source SoundCloud Jan 08 20:46:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:41 volumio volumio[18062]: info: Creating Spotify config file Jan 08 20:46:41 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:41 volumio go-librespot[18426]: go-librespot daemon starting... Jan 08 20:46:41 volumio go-librespot[18427]: time="2026-01-08T20:46:41-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:41 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.178.207 Jan 08 20:46:41 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.178.207 Jan 08 20:46:41 volumio avahi-daemon[664]: Withdrawing address record for 169.254.178.207 on eth0. Jan 08 20:46:41 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:41 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:41 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:41 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:41 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:42 volumio sudo[18425]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 08 20:46:42 volumio sudo[18425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 08 20:46:42 volumio sudo[18425]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:42 volumio go-librespot[18427]: time="2026-01-08T20:46:42-06:00" level=info msg="zeroconf server listening on port 42417" Jan 08 20:46:42 volumio volumio[18062]: info: [squeezelite_mc] Starting proxy server... Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:42 volumio volumio[18062]: info: [1767926802399] CoreMusicLibrary::Adding element YouTube2 Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source SoundCloud Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube2 Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:42 volumio volumio[18062]: info: [1767926802431] CoreMusicLibrary::Adding element YouTube Music Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source SoundCloud Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube2 Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube Music Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:42 volumio volumio[18062]: info: [1767926802450] CoreMusicLibrary::Adding element Podcast Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source SoundCloud Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube2 Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube Music Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Podcast Jan 08 20:46:42 volumio volumio[18062]: info: Loading i18n strings for locale en Jan 08 20:46:42 volumio volumio[18062]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 08 20:46:42 volumio volumio[18062]: Updating browse sources language Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source SoundCloud Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube2 Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube Music Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Podcast Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source SoundCloud Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube2 Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube Music Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Podcast Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:42 volumio volumio[18062]: info: [1767926802533] CoreMusicLibrary::Adding element Volusonic Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source SoundCloud Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube2 Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source YouTube Music Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Podcast Jan 08 20:46:42 volumio volumio[18062]: Cannot find translation for source Volusonic Jan 08 20:46:42 volumio volumio[18062]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 08 20:46:42 volumio volumio[18062]: info: Volumio Calling Home Jan 08 20:46:42 volumio volumio[18062]: info: [squeezelite_mc] Proxy server started on port 34773 Jan 08 20:46:42 volumio volumio[18062]: info: Preparing to generate the ALSA configuration file Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 20:46:42 volumio volumio[18062]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 08 20:46:42 volumio volumio[18062]: info: Discovery: Found device Volumio Jan 08 20:46:42 volumio volumio[18062]: info: CoreCommandRouter::volumioGetState Jan 08 20:46:42 volumio volumio[18062]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:43 volumio volumio[18062]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 08 20:46:43 volumio volumio[18062]: info: Reading ALSA contributions from plugins. Jan 08 20:46:43 volumio volumio[18062]: info: MPD Permissions set Jan 08 20:46:43 volumio volumio[18062]: info: MPD Permissions set Jan 08 20:46:43 volumio volumio[18062]: info: Upmpdcli Daemon Started Jan 08 20:46:43 volumio volumio[18062]: info: Spotify config file written Jan 08 20:46:43 volumio sudo[18458]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 08 20:46:43 volumio sudo[18458]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:43 volumio volumio[18062]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 08 20:46:43 volumio volumio[18062]: info: VolumeController:: Volume=100 Mute =false Jan 08 20:46:43 volumio volumio[18062]: info: CoreStateMachine::pushState Jan 08 20:46:43 volumio volumio[18062]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::volumioPushState Jan 08 20:46:43 volumio volumio[18062]: info: [squeezelite_mc] Server discovery started Jan 08 20:46:43 volumio volumio[18062]: info: [squeezelite_mc] Player finder started Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 08 20:46:43 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 08 20:46:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:43 volumio go-librespot[18467]: go-librespot daemon starting... Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:43 volumio volumio[18062]: info: No need to fix Spotify hosts Jan 08 20:46:43 volumio sudo[18458]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:43 volumio go-librespot[18473]: time="2026-01-08T20:46:43-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:43 volumio go-librespot[18473]: time="2026-01-08T20:46:43-06:00" level=debug msg="app state loaded" Jan 08 20:46:43 volumio go-librespot[18473]: time="2026-01-08T20:46:43-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:43 volumio go-librespot[18473]: time="2026-01-08T20:46:43-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:43 volumio volumio[18062]: 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 08 20:46:43 volumio volumio[18062]: info: Volumio called home Jan 08 20:46:43 volumio go-librespot[18473]: time="2026-01-08T20:46:43-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:46:43 volumio go-librespot[18473]: time="2026-01-08T20:46:43-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 08 20:46:43 volumio go-librespot[18473]: time="2026-01-08T20:46:43-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 08 20:46:43 volumio go-librespot[18473]: time="2026-01-08T20:46:43-06:00" level=info msg="zeroconf server listening on port 38211" Jan 08 20:46:43 volumio volumio[18062]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 08 20:46:43 volumio volumio[18062]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 08 20:46:43 volumio volumio[18062]: 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 08 20:46:44 volumio volumio[18062]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 08 20:46:44 volumio volumio[18062]: SPOTIFY: BQDrIqFjRsqTCmkiQrggm58YJzrpkoy2BViFf3UrR0mshsSlf91Dm1y30dYOoLtJvJtkOb6EoEoW9hGAZh1LQPIYRfDpTMC8tTcq8UajUtZGUIfZSmJrEGyf3qtwlQ5L-JBmvd4GWVHZmSW5wDVeiV_ob0yRGVJWR_ExhygdIUxParMxgBoVOWWlbZZ7ezBdoxSkx24MYhyXPM1XGkYt2p3Ka79ewntTeB7u8iM Jan 08 20:46:44 volumio volumio[18062]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 08 20:46:44 volumio volumio[18062]: info: New Spotify access token = BQDrIqFjRsqTCmkiQrggm58YJzrpkoy2BViFf3UrR0mshsSlf91Dm1y30dYOoLtJvJtkOb6EoEoW9hGAZh1LQPIYRfDpTMC8tTcq8UajUtZGUIfZSmJrEGyf3qtwlQ5L-JBmvd4GWVHZmSW5wDVeiV_ob0yRGVJWR_ExhygdIUxParMxgBoVOWWlbZZ7ezBdoxSkx24MYhyXPM1XGkYt2p3Ka79ewntTeB7u8iM Jan 08 20:46:44 volumio volumio[18062]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 08 20:46:44 volumio go-librespot[18473]: time="2026-01-08T20:46:44-06:00" level=debug msg="obtained new client token: AADX9qvVA05onxNDOZ/FD+4xEnY61q4SLJGO0DQrkHaZwN88KwIqR3r5IF57lkibNUqfMD1zAAuHOKquH9dVySZllIIr6AZJAZegqHu6O2J3DigDe5NJLQkLZRo9olq7xg5V2lneOgylZiE11nX+I+bxjDV9SSqe+Yr4DmbGlTKdxzAnsIXU/1Qt3+iWvUdUARP4TFsgqFXOZ8oYQCl/Yf0HPWuID2ZbMyzjDux5D65e0/gCXDQwnUs=" Jan 08 20:46:44 volumio volumio[18062]: info: Starting Shairport Sync Jan 08 20:46:44 volumio volumio[18062]: info: Starting Shairport Sync Jan 08 20:46:44 volumio volumio[18062]: info: Starting Shairport Sync Jan 08 20:46:44 volumio go-librespot[18473]: time="2026-01-08T20:46:44-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:44 volumio sudo[18486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:46:44 volumio sudo[18486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:44 volumio sudo[18487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:46:44 volumio sudo[18487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:44 volumio go-librespot[18473]: time="2026-01-08T20:46:44-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:44 volumio go-librespot[18473]: time="2026-01-08T20:46:44-06:00" level=debug msg="completed challenge" Jan 08 20:46:44 volumio sudo[18483]: 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 08 20:46:44 volumio sudo[18483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:44 volumio go-librespot[18473]: time="2026-01-08T20:46: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 08 20:46:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:44 volumio sudo[18489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:46:44 volumio sudo[18489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:44 volumio sudo[18483]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:44 volumio volumio[18062]: info: Asound.conf file unchanged, so no further update is needed Jan 08 20:46:44 volumio volumio[18062]: info: Output device has changed, restarting MPD Jan 08 20:46:44 volumio volumio[18062]: info: Output device has changed, restarting Shairport Sync Jan 08 20:46:44 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:44 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:44 volumio sudo[18495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 20:46:44 volumio sudo[18495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:44 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 20:46:44 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 20:46:44 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:46:44 volumio systemd[1]: shairport-sync.service: Consumed 2.070s CPU time. Jan 08 20:46:44 volumio sudo[18495]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:44 volumio sudo[18503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 20:46:44 volumio sudo[18503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:44 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:46:44 volumio volumio[18062]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:46:44 volumio sudo[18489]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:44 volumio sudo[18487]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:44 volumio sudo[18486]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:44 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 08 20:46:44 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 20:46:44 volumio systemd[1]: mpd.service: Consumed 2.977s CPU time. Jan 08 20:46:44 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 08 20:46:44 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 20:46:44 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 20:46:44 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 20:46:44 volumio volumio[18062]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 08 20:46:44 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 20:46:44 volumio sudo[18540]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 08 20:46:44 volumio sudo[18540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:44 volumio sudo[18540]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:44 volumio volumio[18062]: info: MPD Permissions set Jan 08 20:46:44 volumio volumio[18062]: info: Shairport-Sync Started Jan 08 20:46:45 volumio volumio[18062]: Error adding Membership: Error: addMembership EINVAL Jan 08 20:46:45 volumio volumio[18062]: info: Shairport-Sync Started Jan 08 20:46:45 volumio volumio[18062]: info: Shairport-Sync Started Jan 08 20:46:45 volumio volumio[18062]: 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 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:45 volumio sudo[18537]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 08 20:46:45 volumio sudo[18537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 08 20:46:45 volumio sudo[18537]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::volumioGetState Jan 08 20:46:45 volumio volumio[18062]: info: CorePlayQueue::getTrack 0 Jan 08 20:46:45 volumio sudo[18544]: 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 08 20:46:45 volumio volumio[18062]: info: Starting Shairport Sync Jan 08 20:46:45 volumio sudo[18544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:45 volumio sudo[18544]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:45 volumio volumio[18062]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 08 20:46:45 volumio sudo[18554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:46:45 volumio sudo[18554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:45 volumio sudo[18556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 08 20:46:45 volumio sudo[18556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:45 volumio volumio[18062]: 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 08 20:46:45 volumio volumio[18062]: info: Spotify Successfully logged in Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:46:45 volumio volumio[18062]: info: [1767926805438] CoreMusicLibrary::Adding element Spotify Jan 08 20:46:45 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:46:45 volumio volumio[18062]: Cannot find translation for source Bandcamp Discover Jan 08 20:46:45 volumio volumio[18062]: Cannot find translation for source SoundCloud Jan 08 20:46:45 volumio volumio[18062]: Cannot find translation for source YouTube2 Jan 08 20:46:45 volumio volumio[18062]: Cannot find translation for source YouTube Music Jan 08 20:46:45 volumio volumio[18062]: Cannot find translation for source Podcast Jan 08 20:46:45 volumio volumio[18062]: Cannot find translation for source Volusonic Jan 08 20:46:45 volumio volumio[18062]: Cannot find translation for source Spotify Jan 08 20:46:45 volumio systemd[1]: Reloading. Jan 08 20:46:46 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:46 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:46 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:46:46 volumio volumio[18062]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:46:46 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.170.20 Jan 08 20:46:46 volumio avahi-daemon[664]: Registering new address record for 169.254.170.20 on eth0.IPv4. Jan 08 20:46:46 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:46:46 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.170.20 Jan 08 20:46:46 volumio volumio[18062]: info: go-librespot daemon successfully initialized Jan 08 20:46:47 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.170.20 Jan 08 20:46:47 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.170.20 Jan 08 20:46:47 volumio avahi-daemon[664]: Withdrawing address record for 169.254.170.20 on eth0. Jan 08 20:46:47 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:47 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:47 volumio volumio[18062]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 20:46:47 volumio volumio[18062]: Error: addMembership ENODEV Jan 08 20:46:47 volumio volumio[18062]: at Socket.addMembership (node:dgram:860:11) Jan 08 20:46:47 volumio volumio[18062]: at addMembership (/volumio/node_modules/node-ssdp/lib/index.js:264:16) { Jan 08 20:46:47 volumio volumio[18062]: errno: -19, Jan 08 20:46:47 volumio volumio[18062]: code: 'ENODEV', Jan 08 20:46:47 volumio volumio[18062]: syscall: 'addMembership' Jan 08 20:46:47 volumio volumio[18062]: } Jan 08 20:46:47 volumio volumio[18062]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 20:46:48 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 08 20:46:48 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 08 20:46:48 volumio sudo[18556]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 08 20:46:48 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:48 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:48 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:48 volumio go-librespot[18620]: go-librespot daemon starting... Jan 08 20:46:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 20:46:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 20:46:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:46:48 volumio systemd[1]: shairport-sync.service: Consumed 1.543s CPU time. Jan 08 20:46:48 volumio go-librespot[18621]: time="2026-01-08T20:46:48-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:48 volumio go-librespot[18621]: time="2026-01-08T20:46:48-06:00" level=debug msg="app state loaded" Jan 08 20:46:48 volumio go-librespot[18621]: time="2026-01-08T20:46:48-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:48 volumio go-librespot[18621]: time="2026-01-08T20:46:48-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:46:48 volumio sudo[18554]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:49 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:49 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:49 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:49 volumio sudo[18645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-08 20:45' Jan 08 20:46:49 volumio sudo[18645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:49 volumio go-librespot[18621]: time="2026-01-08T20:46:49-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 08 20:46:49 volumio go-librespot[18621]: time="2026-01-08T20:46:49-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 08 20:46:49 volumio go-librespot[18621]: time="2026-01-08T20:46:49-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 08 20:46:49 volumio go-librespot[18621]: time="2026-01-08T20:46:49-06:00" level=info msg="zeroconf server listening on port 36103" Jan 08 20:46:49 volumio go-librespot[18621]: time="2026-01-08T20:46:49-06:00" level=debug msg="obtained new client token: AABJZwpeXf+70avIooBhep6ekyHhtsJE4Gqc8Q3pvDzpy/HQuiwnTg04lQWzWOvu6yZfGYSId6+Gix5j+azudSpqw4wPZNR6DZ693hOqMxdTRF0gJ+C0OS5+yLvDdMBtTFPp0QI4G7j354qxK+JsKw1l8LzvvzYfqFESht6lVK/Q2uI3hUGvQIR5zTw+572oiWY90NfGgfKs16hBCmnqmnfcCHdORbbF6w5Klhvs3Vw5Xex5CPhvct3/HQ==" Jan 08 20:46:49 volumio go-librespot[18621]: time="2026-01-08T20:46:49-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:49 volumio sudo[18645]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:49 volumio go-librespot[18621]: time="2026-01-08T20:46:49-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:49 volumio go-librespot[18621]: time="2026-01-08T20:46:49-06:00" level=debug msg="completed challenge" Jan 08 20:46:49 volumio go-librespot[18621]: time="2026-01-08T20:46:49-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 08 20:46:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:50 volumio mpd[18551]: 2026-01-08T20:46:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 08 20:46:50 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:50 volumio sudo[18400]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:50 volumio sudo[18503]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:50 volumio sudo[18390]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:50 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 08 20:46:50 volumio systemd[1]: volumio.service: Consumed 47.189s CPU time. Jan 08 20:46:50 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 08 20:46:50 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 08 20:46:50 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 08 20:46:50 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 15455. Jan 08 20:46:50 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 08 20:46:50 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 08 20:46:50 volumio systemd[1]: volumio.service: Consumed 47.189s CPU time. Jan 08 20:46:50 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 08 20:46:50 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 08 20:46:51 volumio volumio-remote-updater[14193]: [2026-01-08 20:46:51] [info] asio async_connect error: asio.system:111 (Connection refused) Jan 08 20:46:51 volumio volumio-remote-updater[14193]: [2026-01-08 20:46:51] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Jan 08 20:46:51 volumio volumio-remote-updater[14193]: [2026-01-08 20:46:51] [error] handle_connect error: Connection refused Jan 08 20:46:52 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.213.38 Jan 08 20:46:52 volumio avahi-daemon[664]: Registering new address record for 169.254.213.38 on eth0.IPv4. Jan 08 20:46:52 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:46:52 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:52 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:52 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 08 20:46:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:53 volumio go-librespot[18702]: go-librespot daemon starting... Jan 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-06:00" level=debug msg="app state loaded" Jan 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:53 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.213.38 Jan 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-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 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-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 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-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 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-06:00" level=info msg="zeroconf server listening on port 43485" Jan 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-06:00" level=debug msg="obtained new client token: AADouazn/3w+8dnZHgkijiI4sMtFPZlGwY2k+G+DwT/pIfUmG3TEt4rSMymRQsMmVYczAR/Y31Iao2vG+g4DltsZP/8wYBUP3O+xpPGnEOY29ArGe4YmINT6+8NjWdV0xWYAp0u6R65PsxitP18qrEW0meOdGs6adYnQnTxuRNn9uqzxh6ei00J7WJ79SiFfb2/oaCyqSClVWu3R6AtgDV6zQ3oouNDtpX9x6H1a26LrmZPQ/dxKh6MMaQ==" Jan 08 20:46:53 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.213.38 Jan 08 20:46:53 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.213.38 Jan 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:53 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:53 volumio avahi-daemon[664]: Withdrawing address record for 169.254.213.38 on eth0. Jan 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-06:00" level=debug msg="completed challenge" Jan 08 20:46:53 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:53 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:53 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:53 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:53 volumio go-librespot[18703]: time="2026-01-08T20:46:53-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 08 20:46:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:54 volumio volumio[18671]: info: ------------------------------------------- Jan 08 20:46:54 volumio volumio[18671]: info: ----- Volumio3 ---- Jan 08 20:46:54 volumio volumio[18671]: info: ------------------------------------------- Jan 08 20:46:54 volumio volumio[18671]: info: ----- System startup ---- Jan 08 20:46:54 volumio volumio[18671]: info: ------------------------------------------- Jan 08 20:46:54 volumio volumio[18671]: info: MYVOLUMIO Environment detected Jan 08 20:46:54 volumio volumio[18671]: info: Plugin folders cleanup Jan 08 20:46:54 volumio volumio[18671]: info: Scanning into folder /volumio/app/plugins/ Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category audio_interface Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category miscellanea Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category music_service Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category plugins.json Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category system_controller Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category user_interface Jan 08 20:46:54 volumio volumio[18671]: info: Scanning into folder /data/plugins/ Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category audio_interface Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category music_service Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category system_controller Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category system_hardware Jan 08 20:46:54 volumio volumio[18671]: info: Scanning category user_interface Jan 08 20:46:54 volumio volumio[18671]: info: Plugin folders cleanup completed Jan 08 20:46:54 volumio volumio[18671]: info: ------------------------------------------- Jan 08 20:46:54 volumio volumio[18671]: info: ----- Core plugins startup ---- Jan 08 20:46:54 volumio volumio[18671]: info: ------------------------------------------- Jan 08 20:46:55 volumio volumio[18671]: info: Loading plugins from folder /volumio/app/plugins/ Jan 08 20:46:55 volumio volumio[18671]: info: Adding plugin upnp to MyMusic Plugins Jan 08 20:46:55 volumio volumio[18671]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 08 20:46:55 volumio volumio[18671]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 08 20:46:55 volumio volumio[18671]: info: Loading plugins from folder /data/plugins/ Jan 08 20:46:55 volumio volumio[18671]: info: Loading plugin "system"... Jan 08 20:46:55 volumio volumio[18671]: info: Loading plugin "appearance"... Jan 08 20:46:56 volumio volumio[18671]: info: Loading plugin "network"... Jan 08 20:46:56 volumio volumio[18671]: info: Refreshing Cached IP Addresses Jan 08 20:46:56 volumio sudo[18744]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 20:46:56 volumio sudo[18744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:56 volumio sudo[18744]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:56 volumio sudo[18746]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 20:46:56 volumio volumio[18671]: info: Loading plugin "services"... Jan 08 20:46:56 volumio sudo[18746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:56 volumio sudo[18746]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:56 volumio volumio[18671]: info: Loading plugin "alsa_controller"... Jan 08 20:46:56 volumio sudo[18753]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 08 20:46:56 volumio sudo[18753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:56 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 20:46:56 volumio volumio[18671]: info: Loading plugin "wizard"... Jan 08 20:46:56 volumio volumio[18671]: info: Loading plugin "networkfs"... Jan 08 20:46:56 volumio volumio[18671]: info: Starting Udev Watcher for removable devices Jan 08 20:46:56 volumio volumio[18671]: info: Ignoring mount for partition: boot Jan 08 20:46:56 volumio volumio[18671]: info: Ignoring mount for partition: volumio Jan 08 20:46:56 volumio volumio[18671]: info: Ignoring mount for partition: volumio_data Jan 08 20:46:56 volumio volumio[18671]: info: Mounting Device Wikipedia Jan 08 20:46:56 volumio sudo[18783]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Jan 08 20:46:56 volumio sudo[18783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:46:56 volumio sudo[18783]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:56 volumio volumio[18671]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 08 20:46:56 volumio volumio[18671]: dmesg(1) may have more information after failed mount system call. Jan 08 20:46:56 volumio volumio[18671]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Jan 08 20:46:56 volumio volumio[18671]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Jan 08 20:46:56 volumio volumio[18671]: dmesg(1) may have more information after failed mount system call. Jan 08 20:46:56 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 20:46:56 volumio volumio[18671]: info: Loading plugin "volumio_command_line_client"... Jan 08 20:46:56 volumio volumio[18671]: info: Loading plugin "upnp"... Jan 08 20:46:56 volumio volumio[18671]: info: [1767926816545] Starting Upmpd Daemon Jan 08 20:46:56 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 20:46:56 volumio volumio[18671]: info: Loading plugin "my_music"... Jan 08 20:46:56 volumio volumio[18671]: info: Loading plugin "mpd"... Jan 08 20:46:56 volumio sudo[18753]: pam_unix(sudo:session): session closed for user root Jan 08 20:46:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 08 20:46:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:46:57 volumio go-librespot[18785]: go-librespot daemon starting... Jan 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-06:00" level=debug msg="app state loaded" Jan 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-06:00" level=debug msg="stored credentials not found" Jan 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:46:57 volumio volumio[18671]: info: Loading plugin "upnp_browser"... Jan 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-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 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-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 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-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 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-06:00" level=info msg="zeroconf server listening on port 41739" Jan 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-06:00" level=debug msg="obtained new client token: AAACOUXRafd2r0exD6OmVGyzuU4dcgMw05zLzVMgUAbjdjbGME4J+xRix7zBRxxTadGcHopCp42fJCOia0f/Jw1dHVX55/LjLhj5O+4E3I8oXG+nb6DvTwzXt8RWX+aOZzA1mrd+eYDNRc4NB9MyTV3KqW76CCj4wxTITkIYZNC9eeAQdqdiIvVJGoy4XSdKXYEOsqb5zmczaSB2ljBQLw53vKwDr5DBKqVySwlOBiAtCR4MxYSbfQ6WPA==" Jan 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-06:00" level=debug msg="completed keyexchange" Jan 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-06:00" level=debug msg="completed challenge" Jan 08 20:46:57 volumio go-librespot[18786]: time="2026-01-08T20:46:57-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:46:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:46:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:46:59 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.58.92 Jan 08 20:46:59 volumio avahi-daemon[664]: Registering new address record for 169.254.58.92 on eth0.IPv4. Jan 08 20:46:59 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:46:59 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:59 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:59 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:59 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.58.92 Jan 08 20:46:59 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.58.92 Jan 08 20:46:59 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.58.92 Jan 08 20:46:59 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:46:59 volumio avahi-daemon[664]: Withdrawing address record for 169.254.58.92 on eth0. Jan 08 20:46:59 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:46:59 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:59 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:46:59 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:46:59 volumio volumio[18671]: info: Loading plugin "alarm-clock"... Jan 08 20:47:00 volumio volumio[18671]: info: Loading plugin "airplay_emulation"... Jan 08 20:47:00 volumio volumio[18671]: info: Starting Shairport Sync Jan 08 20:47:00 volumio volumio[18671]: info: Loading plugin "last_100"... Jan 08 20:47:00 volumio volumio[18671]: info: Loading plugin "webradio"... Jan 08 20:47:00 volumio volumio[18671]: info: Loading plugin "i2s_dacs"... Jan 08 20:47:00 volumio volumio[18671]: info: I2S DAC not set, start Auto-detection Jan 08 20:47:00 volumio volumio[18671]: info: Loading plugin "volumiodiscovery"... Jan 08 20:47:00 volumio volumio[18671]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 20:47:00 volumio volumio[18671]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 20:47:00 volumio volumio[18671]: *** WARNING *** For more information see Jan 08 20:47:00 volumio volumio[18671]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 20:47:00 volumio volumio[18671]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 20:47:00 volumio volumio[18671]: *** WARNING *** For more information see Jan 08 20:47:00 volumio node[18671]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 20:47:00 volumio node[18671]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 20:47:00 volumio node[18671]: *** WARNING *** For more information see Jan 08 20:47:00 volumio node[18671]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 20:47:00 volumio node[18671]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 20:47:00 volumio node[18671]: *** WARNING *** For more information see Jan 08 20:47:00 volumio volumio[18671]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 08 20:47:00 volumio volumio[18671]: info: Discovery: Started advertising with name: Volumio Jan 08 20:47:00 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 20:47:00 volumio volumio[18671]: info: Loading plugin "bandcamp"... Jan 08 20:47:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 08 20:47:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:00 volumio go-librespot[18829]: go-librespot daemon starting... Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=debug msg="app state loaded" Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=debug msg="stored credentials not found" Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:47:01 volumio volumio-remote-updater[14193]: [2026-01-08 20:47:01] [connect] Successful connection Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-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 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-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 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=info msg="zeroconf server listening on port 35557" Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=debug msg="obtained new client token: AABBR0LKgTAMYI8rcS3TKncEJh6dFvNV/oamTE4Hi1vmeAC3JMoHNGQXA1xA8Uu0gD5v/8DTeph8fEXXUui79kzqXHZx4tUMOPxJeBNuyoyncE8suFdLcz4XoW/jWvWPGSLKuQQsS4G8rSZ/7G/ksPIAI0ofodER8d9+BETzxbvrd7GtRgHUt7Mpux4NqI95dREfPntLoog7IDTqEXUkUCa4halfkulW0SVXs92LGNSEEF+MGWvjqaXxhA==" Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:47:01 volumio volumio[18671]: info: Plugin calmradio is not enabled Jan 08 20:47:01 volumio volumio[18671]: info: Loading plugin "soundcloud"... Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=debug msg="completed keyexchange" Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=debug msg="completed challenge" Jan 08 20:47:01 volumio go-librespot[18830]: time="2026-01-08T20:47:01-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:47:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:47:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:47:01 volumio volumio[18671]: info: Loading plugin "spop"... Jan 08 20:47:02 volumio kernel: hwmon hwmon1: Voltage normalised Jan 08 20:47:02 volumio volumio[18671]: info: Loading plugin "squeezelite_mc"... Jan 08 20:47:03 volumio volumio[18671]: info: Loading plugin "youtube2"... Jan 08 20:47:04 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.61.146 Jan 08 20:47:04 volumio avahi-daemon[664]: Registering new address record for 169.254.61.146 on eth0.IPv4. Jan 08 20:47:04 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:47:04 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:04 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:47:04 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:04 volumio volumio[18671]: info: Loading plugin "ytcr"... Jan 08 20:47:04 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 08 20:47:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 08 20:47:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:04 volumio go-librespot[18854]: go-librespot daemon starting... Jan 08 20:47:04 volumio go-librespot[18855]: time="2026-01-08T20:47:04-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:47:04 volumio go-librespot[18855]: time="2026-01-08T20:47:04-06:00" level=debug msg="app state loaded" Jan 08 20:47:04 volumio go-librespot[18855]: time="2026-01-08T20:47:04-06:00" level=debug msg="stored credentials not found" Jan 08 20:47:04 volumio go-librespot[18855]: time="2026-01-08T20:47:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:47:05 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.61.146 Jan 08 20:47:05 volumio go-librespot[18855]: time="2026-01-08T20:47:05-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:47:05 volumio go-librespot[18855]: time="2026-01-08T20:47:05-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 08 20:47:05 volumio go-librespot[18855]: time="2026-01-08T20:47:05-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 08 20:47:05 volumio go-librespot[18855]: time="2026-01-08T20:47:05-06:00" level=info msg="zeroconf server listening on port 44053" Jan 08 20:47:05 volumio ntpd[872]: IO: Listen normally on 9911 eth0 169.254.61.146:123 Jan 08 20:47:05 volumio ntpd[872]: IO: new interface(s) found: waking up resolver Jan 08 20:47:05 volumio go-librespot[18855]: time="2026-01-08T20:47:05-06:00" level=debug msg="obtained new client token: AAA7m3P0z1e2tOkY/PDOHv8LOI5biMmU6V42gsg5FhvQxBlcFYq7ilXcBj4At9Rv4otycYpJl0IusORKjoEvb2emzaqcquQab5RS2g6psk/5yVYGrnnV1J3MaeL/8JXT6m6RKbs6cdfQVyj4vjV8pg9m6RbM3CtrjoFyIZAJL/R8kfSe0QyuoG13xb4gQYXVR+grIaRFYiOxWud4agO4MBEgNdL4GGrDpFMpZSVS56BnCxHqsv60gZdMvA==" Jan 08 20:47:05 volumio go-librespot[18855]: time="2026-01-08T20:47:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:47:05 volumio go-librespot[18855]: time="2026-01-08T20:47:05-06:00" level=debug msg="completed keyexchange" Jan 08 20:47:05 volumio go-librespot[18855]: time="2026-01-08T20:47:05-06:00" level=debug msg="completed challenge" Jan 08 20:47:05 volumio go-librespot[18855]: time="2026-01-08T20:47:05-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:47:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:47:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:47:05 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.61.146 Jan 08 20:47:05 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.61.146 Jan 08 20:47:05 volumio avahi-daemon[664]: Withdrawing address record for 169.254.61.146 on eth0. Jan 08 20:47:05 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:47:05 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:05 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:47:05 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:05 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:47:06 volumio volumio[18671]: info: Loading plugin "ytmusic"... Jan 08 20:47:07 volumio ntpd[872]: IO: Deleting interface #9911 eth0, 169.254.61.146#123, interface stats: received=0, sent=0, dropped=0, active_time=2 secs Jan 08 20:47:07 volumio volumio[18671]: info: Plugin now_playing is not enabled Jan 08 20:47:07 volumio volumio[18671]: info: Loading plugin "outputs"... Jan 08 20:47:07 volumio volumio[18671]: info: Loading plugin "albumart"... Jan 08 20:47:07 volumio volumio[18671]: info: Plugin example_plugin is not enabled Jan 08 20:47:07 volumio volumio[18671]: info: Loading plugin "inputs"... Jan 08 20:47:07 volumio volumio[18671]: info: Loading plugin "updater_comm"... Jan 08 20:47:07 volumio volumio[18671]: info: Plugin mpdemulation is not enabled Jan 08 20:47:07 volumio volumio[18671]: info: Loading plugin "rest_api"... Jan 08 20:47:07 volumio volumio[18671]: info: Loading plugin "websocket"... Jan 08 20:47:07 volumio volumio[18671]: info: Starting Socket.io Server version 1.7.4 Jan 08 20:47:07 volumio volumio[18671]: info: Plugin fusiondsp is not enabled Jan 08 20:47:07 volumio volumio[18671]: info: Plugin mpdoutput is not enabled Jan 08 20:47:07 volumio volumio[18671]: info: Plugin RoonBridge is not enabled Jan 08 20:47:07 volumio volumio[18671]: info: Loading plugin "podcast"... Jan 08 20:47:07 volumio volumio[18671]: info: ControllerPodcast::constructor Jan 08 20:47:08 volumio volumio[18671]: info: Loading plugin "volusonic"... Jan 08 20:47:08 volumio volumio[18892]: Forking 3 albumart workers Jan 08 20:47:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 08 20:47:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:08 volumio go-librespot[18932]: go-librespot daemon starting... Jan 08 20:47:08 volumio go-librespot[18933]: time="2026-01-08T20:47:08-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:47:08 volumio go-librespot[18933]: time="2026-01-08T20:47:08-06:00" level=debug msg="app state loaded" Jan 08 20:47:08 volumio go-librespot[18933]: time="2026-01-08T20:47:08-06:00" level=debug msg="stored credentials not found" Jan 08 20:47:08 volumio go-librespot[18933]: time="2026-01-08T20:47:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:47:09 volumio go-librespot[18933]: time="2026-01-08T20:47:09-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:47:09 volumio go-librespot[18933]: time="2026-01-08T20:47:09-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 08 20:47:09 volumio go-librespot[18933]: time="2026-01-08T20:47:09-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 08 20:47:09 volumio go-librespot[18933]: time="2026-01-08T20:47:09-06:00" level=info msg="zeroconf server listening on port 41869" Jan 08 20:47:09 volumio go-librespot[18933]: time="2026-01-08T20:47:09-06:00" level=debug msg="obtained new client token: AAB7oOBSor/K5Gd/bWchsGt87yufSxZt0J326cY2anDFFv8huKKrYywspFMFfrERxSMorPVNSdeCQbqjFuAaKMT3j3MRiFnqox+wDL+UXMs4FcHtO75fCpWZAxTrVgmIiD+wdzc+Brx8yNdeMOUUhhYiJrZEA7XQNUNcnX8pag0tDC0bfVumcRpROOQG5w3c6kCHiabfLzva/tEb7DrAI9Yc5w5gbFkNbi8+Xz8Mo0VQjKyGX9Hv5TaVKg==" Jan 08 20:47:09 volumio go-librespot[18933]: time="2026-01-08T20:47:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:47:10 volumio volumio[18904]: Starting albumart workers Jan 08 20:47:10 volumio volumio[18671]: info: Applying required configuration parameters for plugin volusonic Jan 08 20:47:10 volumio volumio[18671]: info: Loading plugin "backup_restore"... Jan 08 20:47:10 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.80.226 Jan 08 20:47:10 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:47:10 volumio avahi-daemon[664]: Registering new address record for 169.254.80.226 on eth0.IPv4. Jan 08 20:47:10 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:10 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:47:10 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:10 volumio volumio[18902]: Starting albumart workers Jan 08 20:47:10 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.80.226 Jan 08 20:47:10 volumio volumio[18903]: Starting albumart workers Jan 08 20:47:11 volumio volumio[18671]: info: Applying required configuration parameters for plugin backup_restore Jan 08 20:47:11 volumio volumio[18671]: info: Plugin rpi_eeprom_config is not enabled Jan 08 20:47:11 volumio volumio[18671]: info: Plugin rpi_eeprom_updater is not enabled Jan 08 20:47:11 volumio volumio[18671]: info: Loading plugin "scheduledrestart"... Jan 08 20:47:11 volumio volumio[18671]: info: Applying required configuration parameters for plugin scheduledrestart Jan 08 20:47:11 volumio volumio[18671]: info: Plugin Bluetoothremote is not enabled Jan 08 20:47:11 volumio volumio[18671]: info: Plugin music_services_shield is not enabled Jan 08 20:47:11 volumio volumio[18671]: info: Loading plugin "Systeminfo"... Jan 08 20:47:11 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.80.226 Jan 08 20:47:11 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.80.226 Jan 08 20:47:11 volumio avahi-daemon[664]: Withdrawing address record for 169.254.80.226 on eth0. Jan 08 20:47:11 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:47:11 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:11 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:47:11 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:11 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:47:12 volumio volumio[18671]: info: Plugin peppymeterbasic is not enabled Jan 08 20:47:12 volumio volumio[18671]: info: Loading plugin "peppyspectrum"... Jan 08 20:47:12 volumio go-librespot[18933]: time="2026-01-08T20:47:12-06:00" level=debug msg="completed keyexchange" Jan 08 20:47:12 volumio go-librespot[18933]: time="2026-01-08T20:47:12-06:00" level=debug msg="completed challenge" Jan 08 20:47:12 volumio go-librespot[18933]: time="2026-01-08T20:47: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 08 20:47:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:47:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:47:12 volumio volumio[18671]: info: Loading i18n strings for locale en Jan 08 20:47:12 volumio volumio[18671]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 08 20:47:12 volumio volumio[18671]: Updating browse sources language Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::initPlayerControls Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:47:12 volumio volumio[18671]: Express server listening on port 3000 Jan 08 20:47:12 volumio volumio[18671]: [Metrics] WebUI: 19s 388.81ms Jan 08 20:47:12 volumio volumio[18671]: info: CoreStateMachine::resetVolumioState Jan 08 20:47:12 volumio volumio[18671]: info: CoreStateMachine::getcurrentVolume Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:47:12 volumio sudo[18995]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 20:47:12 volumio sudo[18995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:12 volumio sudo[18995]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:12 volumio sudo[18997]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 20:47:12 volumio sudo[18997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:12 volumio sudo[18997]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:12 volumio volumio[18671]: info: Volumio Network Manager: Network status updated: 1 Jan 08 20:47:12 volumio volumio[18671]: info: VolumeController:: Volume=100 Mute =false Jan 08 20:47:12 volumio volumio[18671]: info: CoreStateMachine::pushState Jan 08 20:47:12 volumio volumio[18671]: info: CorePlayQueue::getTrack 0 Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::volumioPushState Jan 08 20:47:12 volumio volumio[18671]: info: CoreStateMachine::updateTrackBlock Jan 08 20:47:12 volumio volumio[18671]: info: CorePlayQueue::getTrackBlock Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 20:47:12 volumio volumio[18671]: info: Reloading queue from file Jan 08 20:47:12 volumio volumio[18671]: info: CoreStateMachine::setRepeat null single undefined Jan 08 20:47:12 volumio volumio[18671]: info: CoreStateMachine::pushState Jan 08 20:47:12 volumio volumio[18671]: info: CorePlayQueue::getTrack 0 Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::volumioPushState Jan 08 20:47:12 volumio volumio[18671]: info: CoreStateMachine::setRandom null Jan 08 20:47:12 volumio volumio[18671]: info: CoreStateMachine::pushState Jan 08 20:47:12 volumio volumio[18671]: info: CorePlayQueue::getTrack 0 Jan 08 20:47:12 volumio volumio[18671]: info: CoreCommandRouter::volumioPushState Jan 08 20:47:12 volumio volumio[18671]: info: Setting Device type: Raspberry PI Jan 08 20:47:13 volumio volumio[18671]: info: VolumeController:: Volume=100 Mute =false Jan 08 20:47:13 volumio volumio[18671]: info: CoreStateMachine::pushState Jan 08 20:47:13 volumio volumio[18671]: info: CorePlayQueue::getTrack 0 Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioPushState Jan 08 20:47:13 volumio sudo[19010]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 08 20:47:13 volumio volumio[18671]: info: Completed loading Core Plugins Jan 08 20:47:13 volumio sudo[19010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:13 volumio volumio[18671]: info: Preparing to generate the ALSA configuration file Jan 08 20:47:13 volumio volumio[18671]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Jan 08 20:47:13 volumio volumio[18671]: info: Discovery: Found device Volumio Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioGetState Jan 08 20:47:13 volumio volumio[18671]: info: CorePlayQueue::getTrack 0 Jan 08 20:47:13 volumio sudo[19010]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:13 volumio volumio[18671]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Jan 08 20:47:13 volumio volumio[18671]: info: Discovery: Found device Volumio Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioGetState Jan 08 20:47:13 volumio volumio[18671]: info: CorePlayQueue::getTrack 0 Jan 08 20:47:13 volumio volumio[18671]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 08 20:47:13 volumio volumio[18671]: info: Reading ALSA contributions from plugins. Jan 08 20:47:13 volumio volumio[18671]: info: Upmpdcli Daemon Started Jan 08 20:47:13 volumio volumio[18671]: info: Asound.conf file unchanged, so no further update is needed Jan 08 20:47:13 volumio volumio[18671]: info: Output device has changed, restarting MPD Jan 08 20:47:13 volumio volumio[18671]: info: Output device has changed, restarting Shairport Sync Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:47:13 volumio sudo[19013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 20:47:13 volumio sudo[19013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:13 volumio sudo[19015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 20:47:13 volumio sudo[19015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:13 volumio sudo[19013]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:13 volumio volumio[18671]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:47:13 volumio volumio[18671]: info: ___________ START PLUGINS ___________ Jan 08 20:47:13 volumio volumio[18671]: info: ControllerMpd::onStart: Initializing MPD Jan 08 20:47:13 volumio volumio[18671]: info: Creating MPD Configuration file Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:47:13 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 08 20:47:13 volumio volumio[18671]: info: [1767926833218] CoreMusicLibrary::Adding element Media Servers Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:13 volumio sudo[19023]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 20:47:13 volumio sudo[19023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:13 volumio sudo[19023]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:13 volumio sudo[19025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 20:47:13 volumio sudo[19025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:47:13 volumio volumio[18671]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:47:13 volumio volumio[18671]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:47:13 volumio volumio[18671]: info: [1767926833334] CoreMusicLibrary::Adding element Last_100 Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:47:13 volumio volumio[18671]: info: [1767926833338] CoreMusicLibrary::Adding element Webradio Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:13 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 08 20:47:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 20:47:13 volumio systemd[1]: mpd.service: Consumed 5.323s CPU time. Jan 08 20:47:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 08 20:47:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 20:47:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 20:47:13 volumio volumio[18671]: info: Initializing BBC Radios Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:47:13 volumio volumio[18671]: info: [1767926833423] CoreMusicLibrary::Adding element Bandcamp Discover Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Bandcamp Discover Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:47:13 volumio volumio[18671]: info: [1767926833434] CoreMusicLibrary::Adding element SoundCloud Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Bandcamp Discover Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source SoundCloud Jan 08 20:47:13 volumio volumio[18671]: info: Creating Spotify config file Jan 08 20:47:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 20:47:13 volumio sudo[19050]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 08 20:47:13 volumio sudo[19050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 08 20:47:13 volumio sudo[19050]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:13 volumio volumio[18671]: info: [squeezelite_mc] Starting proxy server... Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:47:13 volumio volumio[18671]: info: [1767926833802] CoreMusicLibrary::Adding element YouTube2 Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Bandcamp Discover Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source SoundCloud Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube2 Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:47:13 volumio volumio[18671]: info: [1767926833822] CoreMusicLibrary::Adding element YouTube Music Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Bandcamp Discover Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source SoundCloud Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube2 Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube Music Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:47:13 volumio volumio[18671]: info: [1767926833834] CoreMusicLibrary::Adding element Podcast Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Bandcamp Discover Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source SoundCloud Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube2 Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube Music Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Podcast Jan 08 20:47:13 volumio volumio[18671]: info: Loading i18n strings for locale en Jan 08 20:47:13 volumio volumio[18671]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Jan 08 20:47:13 volumio volumio[18671]: Updating browse sources language Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Bandcamp Discover Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source SoundCloud Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube2 Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube Music Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Podcast Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Bandcamp Discover Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source SoundCloud Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube2 Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube Music Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Podcast Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:47:13 volumio volumio[18671]: info: [1767926833882] CoreMusicLibrary::Adding element Volusonic Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Bandcamp Discover Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source SoundCloud Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube2 Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source YouTube Music Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Podcast Jan 08 20:47:13 volumio volumio[18671]: Cannot find translation for source Volusonic Jan 08 20:47:13 volumio volumio[18671]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Jan 08 20:47:13 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 08 20:47:13 volumio volumio[18671]: info: Volumio Calling Home Jan 08 20:47:14 volumio volumio[18671]: info: [squeezelite_mc] Proxy server started on port 46027 Jan 08 20:47:14 volumio volumio[18671]: info: Preparing to generate the ALSA configuration file Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 20:47:14 volumio volumio[18671]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 08 20:47:14 volumio volumio[18671]: info: Reading ALSA contributions from plugins. Jan 08 20:47:14 volumio volumio[18671]: info: MPD Permissions set Jan 08 20:47:14 volumio volumio[18671]: info: MPD Permissions set Jan 08 20:47:14 volumio volumio[18671]: info: Spotify config file written Jan 08 20:47:14 volumio sudo[19060]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 08 20:47:14 volumio sudo[19060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:14 volumio volumio[18671]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: No need to fix Spotify hosts Jan 08 20:47:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:14 volumio go-librespot[19069]: go-librespot daemon starting... Jan 08 20:47:14 volumio sudo[19060]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:14 volumio go-librespot[19073]: time="2026-01-08T20:47:14-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:47:14 volumio go-librespot[19073]: time="2026-01-08T20:47:14-06:00" level=debug msg="app state loaded" Jan 08 20:47:14 volumio go-librespot[19073]: time="2026-01-08T20:47:14-06:00" level=debug msg="stored credentials not found" Jan 08 20:47:14 volumio go-librespot[19073]: time="2026-01-08T20:47:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:47:14 volumio volumio[18671]: 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 08 20:47:14 volumio volumio[18671]: info: VolumeController:: Volume=100 Mute =false Jan 08 20:47:14 volumio volumio[18671]: info: CoreStateMachine::pushState Jan 08 20:47:14 volumio volumio[18671]: info: CorePlayQueue::getTrack 0 Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::volumioPushState Jan 08 20:47:14 volumio volumio[18671]: info: [squeezelite_mc] Server discovery started Jan 08 20:47:14 volumio volumio[18671]: info: [squeezelite_mc] Player finder started Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:47:14 volumio volumio[18671]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Jan 08 20:47:14 volumio volumio[18671]: info: Volumio called home Jan 08 20:47:14 volumio go-librespot[19073]: time="2026-01-08T20:47: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:47:14 volumio go-librespot[19073]: time="2026-01-08T20:47:14-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 08 20:47:14 volumio go-librespot[19073]: time="2026-01-08T20:47:14-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 08 20:47:14 volumio volumio[18671]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 08 20:47:14 volumio volumio[18671]: SPOTIFY: BQDAMh-II_CqO2ksjpfSf2ZgHCpAeiQCJpKM8RRCLLGIfq5RSTwq3vnxCI5B37hdyjLJne_7kXV1itN5uRyKdQ21rYg2RJLP-d7Cc1dj5n99qL1QQn7-VJeojGMSqCG1w3DY4BQ4bjLer8iOvqgKNU02B3HTlBjK5Q0XA0MUTRMQFev2L7c-88k9GXGe12p6SgdaPbN2rv32FhS-EhD0l9Y0qXq2pPvkUL9FWJM Jan 08 20:47:14 volumio volumio[18671]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 08 20:47:14 volumio volumio[18671]: info: New Spotify access token = BQDAMh-II_CqO2ksjpfSf2ZgHCpAeiQCJpKM8RRCLLGIfq5RSTwq3vnxCI5B37hdyjLJne_7kXV1itN5uRyKdQ21rYg2RJLP-d7Cc1dj5n99qL1QQn7-VJeojGMSqCG1w3DY4BQ4bjLer8iOvqgKNU02B3HTlBjK5Q0XA0MUTRMQFev2L7c-88k9GXGe12p6SgdaPbN2rv32FhS-EhD0l9Y0qXq2pPvkUL9FWJM Jan 08 20:47:14 volumio volumio[18671]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 08 20:47:14 volumio go-librespot[19073]: time="2026-01-08T20:47:14-06:00" level=info msg="zeroconf server listening on port 39401" Jan 08 20:47:14 volumio volumio[18671]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Jan 08 20:47:14 volumio volumio[18671]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Jan 08 20:47:14 volumio volumio[18671]: 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 08 20:47:14 volumio volumio[18671]: info: Starting Shairport Sync Jan 08 20:47:14 volumio volumio[18671]: info: Starting Shairport Sync Jan 08 20:47:15 volumio go-librespot[19073]: time="2026-01-08T20:47:15-06:00" level=debug msg="obtained new client token: AACYo8g778qikAMRjkaV7cB8i9jt3ATRUTT4jfGHXBwAGqm7UQvO+YlU+LQdHl6MbQ6tVpzWAFIFEgETsHHE8SxoPuMX71PYRlWQjavLoZmILZfuEq1iJJqgVhKLLgRDnuml54maU2/NlczBJlEHkowPdfhO1BuNC6xXg5l2NUgPhtY6/rUenis2fP0Nt1t+cYtMvly4THyY2S+t+/717fQ2gX+kPf58itylOg74ml7QojxYZXT3eIY4SQ==" Jan 08 20:47:15 volumio volumio[18671]: info: Starting Shairport Sync Jan 08 20:47:15 volumio sudo[19092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:47:15 volumio sudo[19092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:15 volumio go-librespot[19073]: time="2026-01-08T20:47:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:47:15 volumio sudo[19094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:47:15 volumio sudo[19094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:15 volumio sudo[19096]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:47:15 volumio sudo[19096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:15 volumio go-librespot[19073]: time="2026-01-08T20:47:15-06:00" level=debug msg="completed keyexchange" Jan 08 20:47:15 volumio go-librespot[19073]: time="2026-01-08T20:47:15-06:00" level=debug msg="completed challenge" Jan 08 20:47:15 volumio volumio[18671]: info: Asound.conf file unchanged, so no further update is needed Jan 08 20:47:15 volumio volumio[18671]: info: Output device has changed, restarting MPD Jan 08 20:47:15 volumio go-librespot[19073]: time="2026-01-08T20:47:15-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:47:15 volumio sudo[19089]: 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 08 20:47:15 volumio sudo[19089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:15 volumio volumio[18671]: info: Output device has changed, restarting Shairport Sync Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:47:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:47:15 volumio sudo[19089]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:15 volumio sudo[19104]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 20:47:15 volumio sudo[19104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 20:47:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 20:47:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:47:15 volumio systemd[1]: shairport-sync.service: Consumed 1.979s CPU time. Jan 08 20:47:15 volumio volumio[18671]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 20:47:15 volumio sudo[19103]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 20:47:15 volumio sudo[19103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:15 volumio sudo[19103]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:47:15 volumio sudo[19092]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:15 volumio sudo[19096]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:15 volumio sudo[19094]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:15 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 08 20:47:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 20:47:15 volumio systemd[1]: mpd.service: Consumed 2.025s CPU time. Jan 08 20:47:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 08 20:47:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 20:47:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 20:47:15 volumio mpd_monitor.sh[19090]: MPD error: Connection reset by peer Jan 08 20:47:15 volumio mpd_monitor.sh[17977]: MPD Monitor Service: MPD Appears to be inactive, restarting Jan 08 20:47:15 volumio mpd_monitor.sh[19129]: mpd: no process found Jan 08 20:47:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 20:47:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 20:47:15 volumio volumio[18671]: info: MPD Permissions set Jan 08 20:47:15 volumio volumio[18671]: info: Shairport-Sync Started Jan 08 20:47:15 volumio volumio[18671]: Error adding Membership: Error: addMembership EINVAL Jan 08 20:47:15 volumio volumio[18671]: info: Shairport-Sync Started Jan 08 20:47:15 volumio volumio[18671]: info: Shairport-Sync Started Jan 08 20:47:15 volumio volumio[18671]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Jan 08 20:47:15 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 08 20:47:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 08 20:47:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 08 20:47:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 08 20:47:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 08 20:47:15 volumio sudo[19136]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Jan 08 20:47:15 volumio sudo[19136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:15 volumio sudo[19136]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 20:47:15 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 08 20:47:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 08 20:47:16 volumio volumio[18671]: 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 08 20:47:16 volumio volumio[18671]: info: CoreCommandRouter::volumioGetState Jan 08 20:47:16 volumio volumio[18671]: info: CorePlayQueue::getTrack 0 Jan 08 20:47:16 volumio volumio-remote-updater[14193]: [2026-01-08 20:47:16] [connect] Successful connection Jan 08 20:47:16 volumio volumio[18671]: info: Starting Shairport Sync Jan 08 20:47:16 volumio volumio-remote-updater[14193]: [2026-01-08 20:47:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767926836 101 Jan 08 20:47:16 volumio volumio[18671]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Jan 08 20:47:16 volumio volumio[18671]: 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 08 20:47:16 volumio volumio[18671]: info: Spotify Successfully logged in Jan 08 20:47:16 volumio sudo[19149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 20:47:16 volumio sudo[19149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:16 volumio volumio[18671]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 20:47:16 volumio volumio[18671]: info: [1767926836255] CoreMusicLibrary::Adding element Spotify Jan 08 20:47:16 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 20:47:16 volumio volumio[18671]: Cannot find translation for source Bandcamp Discover Jan 08 20:47:16 volumio volumio[18671]: Cannot find translation for source SoundCloud Jan 08 20:47:16 volumio volumio[18671]: Cannot find translation for source YouTube2 Jan 08 20:47:16 volumio volumio[18671]: Cannot find translation for source YouTube Music Jan 08 20:47:16 volumio volumio[18671]: Cannot find translation for source Podcast Jan 08 20:47:16 volumio volumio[18671]: Cannot find translation for source Volusonic Jan 08 20:47:16 volumio volumio[18671]: Cannot find translation for source Spotify Jan 08 20:47:16 volumio sudo[19147]: 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 08 20:47:16 volumio sudo[19147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:16 volumio sudo[19147]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:16 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 08 20:47:16 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 08 20:47:16 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:47:16 volumio volumio[18671]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Jan 08 20:47:16 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 08 20:47:16 volumio sudo[19149]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:16 volumio sudo[19144]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 08 20:47:16 volumio sudo[19144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 08 20:47:16 volumio sudo[19144]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:16 volumio sudo[19167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 08 20:47:16 volumio sudo[19167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:16 volumio systemd[1]: Reloading. Jan 08 20:47:16 volumio volumio[18671]: info: Shairport-Sync Started Jan 08 20:47:16 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:16 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:16 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 20:47:16 volumio volumio[18671]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 20:47:17 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.74.50 Jan 08 20:47:17 volumio avahi-daemon[664]: Registering new address record for 169.254.74.50 on eth0.IPv4. Jan 08 20:47:17 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:47:17 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.74.50 Jan 08 20:47:17 volumio volumio[18671]: info: go-librespot daemon successfully initialized Jan 08 20:47:18 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.74.50 Jan 08 20:47:18 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.74.50 Jan 08 20:47:18 volumio avahi-daemon[664]: Withdrawing address record for 169.254.74.50 on eth0. Jan 08 20:47:18 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:47:18 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:47:18 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 08 20:47:18 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 08 20:47:19 volumio sudo[19167]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 08 20:47:19 volumio volumio[18671]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:47:19 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:19 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:47:19 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:19 volumio sudo[19236]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:47:19 volumio sudo[19236]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:19 volumio go-librespot[19239]: go-librespot daemon starting... Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=debug msg="app state loaded" Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=debug msg="stored credentials not found" Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:47:19 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:19 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:47:19 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:19 volumio sudo[19236]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:19 volumio volumio[18671]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Jan 08 20:47:19 volumio sudo[19249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Jan 08 20:47:19 volumio sudo[19249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:19 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=info msg="zeroconf server listening on port 38645" Jan 08 20:47:19 volumio systemd[1]: squeezelite.service: Deactivated successfully. Jan 08 20:47:19 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 08 20:47:19 volumio sudo[19249]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=debug msg="obtained new client token: AACzq2/QMfJs/R1tD2MBdcc19Hj0GDJDMKlKSN4Vim+ij3Y6KywTVKyL9DZ1BLiJ1pCu4j/sMU8GpNuMiGGUnmpoyaZOIVcFJgShd7NhiDbpdx2Z4kWhQvMhay8wHTJyg/ORq7P+mTTO73hcudQoHoh00G6gXNKOWmLiWDJ6yiFhuWe7KvOgoPNdsDIu66bF8vI8ZSFHQswjRbMgQZkwMO00I7JRojaQ6b1iI7c9VgTzdbWYqZ3xsxS/aQ==" Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=debug msg="completed keyexchange" Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=debug msg="completed challenge" Jan 08 20:47:19 volumio go-librespot[19240]: time="2026-01-08T20:47:19-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:47:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:47:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:47:20 volumio volumio[18671]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:47:20 volumio sudo[19252]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:47:20 volumio sudo[19252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:20 volumio sudo[19252]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:20 volumio volumio[18671]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Jan 08 20:47:20 volumio sudo[19256]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Jan 08 20:47:20 volumio sudo[19256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:20 volumio sudo[19256]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:20 volumio volumio[18671]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Jan 08 20:47:20 volumio sudo[19259]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Jan 08 20:47:20 volumio sudo[19259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:20 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Jan 08 20:47:20 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Jan 08 20:47:20 volumio sudo[19259]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:20 volumio mpd[19170]: 2026-01-08T20:47:20 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 08 20:47:20 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 08 20:47:20 volumio sudo[19015]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:20 volumio mpd_monitor.sh[17977]: MPD Monitor Service: MPD restarted due to no mpc output. Jan 08 20:47:20 volumio sudo[19104]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:20 volumio sudo[19025]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:20 volumio volumio[18671]: error: MPD error: The expression evaluated to a falsy value: Jan 08 20:47:20 volumio volumio[18671]: assert.ok(self.idling) Jan 08 20:47:20 volumio volumio[18671]: error: The expression evaluated to a falsy value: Jan 08 20:47:20 volumio volumio[18671]: assert.ok(self.idling) Jan 08 20:47:20 volumio volumio[18671]: error: MPD error: The expression evaluated to a falsy value: Jan 08 20:47:20 volumio volumio[18671]: assert.ok(self.idling) Jan 08 20:47:20 volumio volumio[18671]: error: The expression evaluated to a falsy value: Jan 08 20:47:20 volumio volumio[18671]: assert.ok(self.idling) Jan 08 20:47:20 volumio volumio[18671]: info: Initializing connection to go-librespot Websocket Jan 08 20:47:20 volumio volumio[18671]: info: MPD running with PID19170 Jan 08 20:47:20 volumio volumio[18671]: ,establishing connection Jan 08 20:47:20 volumio volumio[18671]: error: updateQueue error: null Jan 08 20:47:20 volumio volumio[18671]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 08 20:47:20 volumio volumio[18671]: error: updateQueue error: null Jan 08 20:47:20 volumio volumio[18671]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:47:20 volumio sudo[19271]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:47:20 volumio sudo[19271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:21 volumio sudo[19271]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:21 volumio kernel: hwmon hwmon1: Voltage normalised Jan 08 20:47:21 volumio volumio[18671]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:47:21 volumio sudo[19275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:47:21 volumio sudo[19275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:21 volumio sudo[19275]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:22 volumio volumio[18671]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:47:22 volumio sudo[19278]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:47:22 volumio sudo[19278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:22 volumio sudo[19278]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:22 volumio volumio[18671]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:47:22 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.55.206 Jan 08 20:47:22 volumio avahi-daemon[664]: Registering new address record for 169.254.55.206 on eth0.IPv4. Jan 08 20:47:22 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:47:22 volumio sudo[19281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:47:22 volumio sudo[19281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 08 20:47:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:22 volumio go-librespot[19299]: go-librespot daemon starting... Jan 08 20:47:22 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:22 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:47:22 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:22 volumio go-librespot[19300]: time="2026-01-08T20:47:22-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:47:22 volumio go-librespot[19300]: time="2026-01-08T20:47:22-06:00" level=debug msg="app state loaded" Jan 08 20:47:22 volumio go-librespot[19300]: time="2026-01-08T20:47:22-06:00" level=debug msg="stored credentials not found" Jan 08 20:47:22 volumio go-librespot[19300]: time="2026-01-08T20:47:22-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:47:22 volumio sudo[19281]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:22 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.55.206 Jan 08 20:47:23 volumio go-librespot[19300]: time="2026-01-08T20:47:23-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 08 20:47:23 volumio go-librespot[19300]: time="2026-01-08T20:47:23-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 08 20:47:23 volumio go-librespot[19300]: time="2026-01-08T20:47:23-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 08 20:47:23 volumio go-librespot[19300]: time="2026-01-08T20:47:23-06:00" level=info msg="zeroconf server listening on port 44053" Jan 08 20:47:23 volumio go-librespot[19300]: time="2026-01-08T20:47:23-06:00" level=debug msg="obtained new client token: AADH/bKQVxSVdEANi2gsWJt9r8o7UUbt77yM//AjqzbnS1Pd9AanIOzWaZ4NBldkO81CXSGuwRBt/qIdPKBMB3U2rx8CMWVnpu/O3UTzKUj64aAZ+WRMYPg/g4y8bBNXleBwxiAUYcWmEBhBeIdh0PK0s1GhOo/7fRyCH/h0R6GYp5i8WL9zgX6j2sDki72JRkrqDgxWWpzLvVzP7oBNqiQXzYAcuilQUnZzVsM6fBCj4ba+MzpRoDY=" Jan 08 20:47:23 volumio go-librespot[19300]: time="2026-01-08T20:47:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:47:23 volumio go-librespot[19300]: time="2026-01-08T20:47:23-06:00" level=debug msg="completed keyexchange" Jan 08 20:47:23 volumio go-librespot[19300]: time="2026-01-08T20:47:23-06:00" level=debug msg="completed challenge" Jan 08 20:47:23 volumio go-librespot[19300]: time="2026-01-08T20:47:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:47:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:47:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:47:23 volumio volumio[18671]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Jan 08 20:47:23 volumio sudo[19308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Jan 08 20:47:23 volumio sudo[19308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:23 volumio sudo[19308]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:23 volumio volumio[18671]: info: Completed starting Core Plugins Jan 08 20:47:23 volumio volumio[18671]: info: ------------------------------------------- Jan 08 20:47:23 volumio volumio[18671]: info: ----- MyVolumio plugins startup ---- Jan 08 20:47:23 volumio volumio[18671]: info: ------------------------------------------- Jan 08 20:47:23 volumio volumio[18671]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 08 20:47:23 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.55.206 Jan 08 20:47:23 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.55.206 Jan 08 20:47:23 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:47:23 volumio avahi-daemon[664]: Withdrawing address record for 169.254.55.206 on eth0. Jan 08 20:47:23 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:23 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:47:23 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:23 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:47:23 volumio sudo[19326]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 20:47:23 volumio sudo[19326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:23 volumio sudo[19329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 20:47:23 volumio sudo[19329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:23 volumio sudo[19331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 08 20:47:23 volumio sudo[19331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 08 20:47:23 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 08 20:47:23 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 08 20:47:23 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 08 20:47:23 volumio volumio[18671]: info: Initializing connection to go-librespot Websocket Jan 08 20:47:23 volumio volumio[18671]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 08 20:47:23 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 08 20:47:23 volumio sudo[19329]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:23 volumio sudo[19331]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:23 volumio sudo[19326]: pam_unix(sudo:session): session closed for user root Jan 08 20:47:23 volumio mpd_monitor.sh[19335]: MPD Monitor Service: Starting MPD Monitor Service Jan 08 20:47:23 volumio volumio[18671]: info: Successfully started MPD Monitor Jan 08 20:47:23 volumio volumio[18671]: info: Successfully started MPD Monitor Jan 08 20:47:23 volumio volumio[18671]: info: Successfully started MPD Monitor Jan 08 20:47:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 08 20:47:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:26 volumio go-librespot[19339]: go-librespot daemon starting... Jan 08 20:47:26 volumio go-librespot[19348]: time="2026-01-08T20:47:26-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:47:26 volumio go-librespot[19348]: time="2026-01-08T20:47:26-06:00" level=debug msg="app state loaded" Jan 08 20:47:26 volumio go-librespot[19348]: time="2026-01-08T20:47:26-06:00" level=debug msg="stored credentials not found" Jan 08 20:47:26 volumio go-librespot[19348]: time="2026-01-08T20:47:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:47:26 volumio volumio[18671]: info: Initializing connection to go-librespot Websocket Jan 08 20:47:26 volumio go-librespot[19348]: time="2026-01-08T20:47:26-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:47:26 volumio go-librespot[19348]: time="2026-01-08T20:47:26-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 08 20:47:26 volumio go-librespot[19348]: time="2026-01-08T20:47:26-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 08 20:47:26 volumio go-librespot[19348]: time="2026-01-08T20:47:26-06:00" level=info msg="zeroconf server listening on port 45717" Jan 08 20:47:27 volumio go-librespot[19348]: time="2026-01-08T20:47:27-06:00" level=debug msg="obtained new client token: AADUmOwGskWjIxZtXlXiA45dckQ9FNLKT8iJVvCui68WsMgzlb06lAuKVEpxMoawDXhSCyatxDEqyea9OUyIxBtEl4/2nQGkJHEWZPCOCRTAgLtuEragzSh56oIHXG1bnU5wydvE+CMnu6nMxtlT+/13p53iY/Aoi3ln36ihR7MemvpUPcAeFs27Lsrhdh63MbaeROOOO3780EDMrxIGRW8c63UoQCM46RgWFUhMrJ4kZF+Yr2CKN9o=" Jan 08 20:47:27 volumio go-librespot[19348]: time="2026-01-08T20:47:27-06:00" level=debug msg="new websocket client" Jan 08 20:47:27 volumio go-librespot[19348]: time="2026-01-08T20:47:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:47:27 volumio go-librespot[19348]: time="2026-01-08T20:47:27-06:00" level=debug msg="completed keyexchange" Jan 08 20:47:27 volumio go-librespot[19348]: time="2026-01-08T20:47:27-06:00" level=debug msg="completed challenge" Jan 08 20:47:27 volumio go-librespot[19348]: time="2026-01-08T20:47:27-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:47:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:47:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:47:27 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 08 20:47:27 volumio volumio[18671]: info: Connection to go-librespot Websocket established Jan 08 20:47:27 volumio volumio[18671]: info: Connection to go-librespot Websocket closed Jan 08 20:47:28 volumio dhcpcd[684]: eth0: using IPv4LL address 169.254.97.245 Jan 08 20:47:28 volumio avahi-daemon[664]: Registering new address record for 169.254.97.245 on eth0.IPv4. Jan 08 20:47:28 volumio dhcpcd[684]: eth0: adding route to 169.254.0.0/16 Jan 08 20:47:29 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:29 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:47:29 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:29 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.97.245 Jan 08 20:47:30 volumio dhcpcd[684]: eth0: 80:69:1a:20:db:59(80:69:1a:20:db:59) claims 169.254.97.245 Jan 08 20:47:30 volumio dhcpcd[684]: eth0: 10 second defence failed for 169.254.97.245 Jan 08 20:47:30 volumio avahi-daemon[664]: Withdrawing address record for 169.254.97.245 on eth0. Jan 08 20:47:30 volumio dhcpcd[684]: eth0: deleting route to 169.254.0.0/16 Jan 08 20:47:30 volumio dhcpcd[684]: eth0: probing for an IPv4LL address Jan 08 20:47:30 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:30 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jan 08 20:47:30 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jan 08 20:47:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 08 20:47:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 08 20:47:30 volumio go-librespot[19396]: go-librespot daemon starting... Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=info msg="running go-librespot 0.4.0" Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=debug msg="app state loaded" Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=debug msg="stored credentials not found" Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 08 20:47:30 volumio volumio[18671]: info: Getting Spotify volume Jan 08 20:47:30 volumio volumio[18671]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=info msg="zeroconf server listening on port 42711" Jan 08 20:47:30 volumio volumio[18671]: info: CoreCommandRouter::volumioGetState Jan 08 20:47:30 volumio volumio[18671]: info: CorePlayQueue::getTrack 0 Jan 08 20:47:30 volumio volumio[18671]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 08 20:47:30 volumio volumio[18671]: SPOTIFY: SPOTIFY VOLUME undefined Jan 08 20:47:30 volumio volumio[18671]: SPOTIFY: VOLUMIO VOLUME 100 Jan 08 20:47:30 volumio volumio[18671]: info: Aligning Spotify Volume to Volumio Volume Jan 08 20:47:30 volumio volumio[18671]: info: CoreCommandRouter::volumioGetState Jan 08 20:47:30 volumio volumio[18671]: info: CorePlayQueue::getTrack 0 Jan 08 20:47:30 volumio volumio[18671]: info: Setting Spotify Volume from Volumio: 100 Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=debug msg="obtained new client token: AACKzhaBU8qCTnfcImiTGH3fg3sQ66HggZwPxm8ykZRLaJ79ys+0E2uARq3zf2G3G1M/Qe+E7+RrVMlN1RloH47c/AMGcFTGQxB3SemZ5SG3kiROnoaYqVPyL2v+zCfY/NCARVasCTaNkVlqdM4ROaXZOISF9CxFe0GlT8sCWlFG0yXL1HU3h8vrZzRP2zt/8AS1bKUoW3BxAfp2YiG+z0/Hbgd/kxYjfz7NDErzW60xxmZh9CrV7fvjCg==" Jan 08 20:47:30 volumio volumio[18671]: info: Initializing connection to go-librespot Websocket Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=debug msg="new websocket client" Jan 08 20:47:30 volumio volumio[18671]: info: Connection to go-librespot Websocket established Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=debug msg="completed keyexchange" Jan 08 20:47:30 volumio go-librespot[19397]: time="2026-01-08T20:47:30-06:00" level=debug msg="completed challenge" Jan 08 20:47:31 volumio go-librespot[19397]: time="2026-01-08T20:47:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jan 08 20:47:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 08 20:47:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 08 20:47:31 volumio volumio[18671]: info: Connection to go-librespot Websocket closed Jan 08 20:47:31 volumio volumio[18671]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 20:47:31 volumio volumio[18671]: Error: socket hang up Jan 08 20:47:31 volumio volumio[18671]: at connResetException (node:internal/errors:720:14) Jan 08 20:47:31 volumio volumio[18671]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 08 20:47:31 volumio volumio[18671]: at Socket.emit (node:events:526:35) Jan 08 20:47:31 volumio volumio[18671]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 08 20:47:31 volumio volumio[18671]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 08 20:47:31 volumio volumio[18671]: code: 'ECONNRESET', Jan 08 20:47:31 volumio volumio[18671]: response: undefined Jan 08 20:47:31 volumio volumio[18671]: } Jan 08 20:47:31 volumio volumio[18671]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 08 20:47:31 volumio sudo[19418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-08 20:46' Jan 08 20:47:31 volumio sudo[19418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025" VOLUMIO_VERSION="4.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"