Dec 10 23:17:00 volumio volumio-remote-updater[632]: [2025-12-10 23:17:00] [connect] Successful connection Dec 10 23:17:04 volumio volumio[1176]: info: Loading i18n strings for locale en Dec 10 23:17:04 volumio volumio[1176]: Updating browse sources language Dec 10 23:17:04 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 23:17:04 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5. Dec 10 23:17:04 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 10 23:17:04 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 10 23:17:05 volumio upmpdcli[1397]: Could not open config: /tmp/upmpdcli.conf Dec 10 23:17:05 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 10 23:17:05 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::initPlayerControls Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 23:17:08 volumio volumio[1176]: Express server listening on port 3000 Dec 10 23:17:08 volumio volumio[1176]: [Metrics] WebUI: 45s 917.48ms Dec 10 23:17:08 volumio ntpd[930]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Dec 10 23:17:08 volumio ntpd[930]: DNS: dns_check: DNS error: -11, System error Dec 10 23:17:08 volumio ntpd[930]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Dec 10 23:17:08 volumio volumio[1176]: info: CoreStateMachine::resetVolumioState Dec 10 23:17:08 volumio volumio[1176]: info: CoreStateMachine::getcurrentVolume Dec 10 23:17:08 volumio volumio[1176]: info: CoreCommandRouter::volumioRetrievevolume Dec 10 23:17:08 volumio volumio[1340]: Starting albumart workers Dec 10 23:17:09 volumio volumio[1339]: Starting albumart workers Dec 10 23:17:09 volumio ntpd[930]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Dec 10 23:17:09 volumio volumio[1341]: Starting albumart workers Dec 10 23:17:09 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:09 volumio sudo[1404]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 10 23:17:09 volumio sudo[1404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:09 volumio sudo[1406]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 10 23:17:09 volumio sudo[1404]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:09 volumio sudo[1406]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:09 volumio sudo[1406]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:10 volumio volumio[1176]: info: Volumio Network Manager: Network status updated: 2 Dec 10 23:17:12 volumio volumio[1176]: info: VolumeController:: Volume=34 Mute =false Dec 10 23:17:12 volumio volumio[1176]: info: CoreStateMachine::pushState Dec 10 23:17:12 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:12 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 23:17:12 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Dec 10 23:17:12 volumio volumio[1176]: info: CoreStateMachine::updateTrackBlock Dec 10 23:17:12 volumio volumio[1176]: info: CorePlayQueue::getTrackBlock Dec 10 23:17:12 volumio volumio[1176]: info: CoreCommandRouter::volumioRetrievevolume Dec 10 23:17:13 volumio volumio[1176]: info: Reloading queue from file Dec 10 23:17:13 volumio volumio[1176]: info: CoreStateMachine::setRepeat null single undefined Dec 10 23:17:13 volumio volumio[1176]: info: CoreStateMachine::pushState Dec 10 23:17:13 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:13 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 23:17:13 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Dec 10 23:17:13 volumio volumio[1176]: info: CoreStateMachine::setRandom false Dec 10 23:17:13 volumio volumio[1176]: info: CoreStateMachine::pushState Dec 10 23:17:13 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:13 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 10 23:17:13 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Dec 10 23:17:13 volumio volumio[1176]: info: Setting Device type: Raspberry PI Dec 10 23:17:14 volumio volumio[1176]: info: VolumeController:: Volume=34 Mute =false Dec 10 23:17:14 volumio volumio[1176]: info: CoreStateMachine::pushState Dec 10 23:17:14 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:14 volumio volumio[1176]: info: CoreCommandRouter::volumioPushState Dec 10 23:17:14 volumio volumio[1176]: info: Completed loading Core Plugins Dec 10 23:17:14 volumio sudo[1435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 10 23:17:15 volumio sudo[1435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:15 volumio volumio[1176]: info: Preparing to generate the ALSA configuration file Dec 10 23:17:15 volumio volumio-remote-updater[632]: [2025-12-10 23:17:15] [connect] Successful connection Dec 10 23:17:15 volumio volumio[1176]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Dec 10 23:17:15 volumio volumio[1176]: info: Reading ALSA contributions from plugins. Dec 10 23:17:15 volumio volumio-remote-updater[632]: [2025-12-10 23:17:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765405035 101 Dec 10 23:17:16 volumio volumio[1176]: 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 Dec 10 23:17:17 volumio volumio[1176]: info: Asound.conf file unchanged, so no further update is needed Dec 10 23:17:17 volumio volumio[1176]: info: Output device has changed, restarting MPD Dec 10 23:17:17 volumio volumio[1176]: info: Output device has changed, restarting Shairport Sync Dec 10 23:17:17 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:17 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:17 volumio sudo[1438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 23:17:17 volumio sudo[1438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:17 volumio volumio[1176]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 23:17:17 volumio sudo[1440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 23:17:17 volumio sudo[1438]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:17 volumio volumio[1176]: info: ___________ START PLUGINS ___________ Dec 10 23:17:17 volumio sudo[1440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:17 volumio volumio[1176]: info: ControllerMpd::onStart: Initializing MPD Dec 10 23:17:17 volumio volumio[1176]: info: Creating MPD Configuration file Dec 10 23:17:18 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 10 23:17:18 volumio volumio[1176]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 23:17:18 volumio volumio[1176]: info: [1765405038199] CoreMusicLibrary::Adding element Media Servers Dec 10 23:17:18 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 23:17:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 23:17:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 23:17:18 volumio volumio[1176]: info: UPNP Browser: Client initialized successfully Dec 10 23:17:18 volumio sudo[1448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 23:17:18 volumio sudo[1448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:18 volumio sudo[1448]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:18 volumio sudo[1450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 23:17:18 volumio sudo[1450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:18 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:18 volumio sudo[1454]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 23:17:18 volumio sudo[1454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 23:17:18 volumio sudo[1470]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 10 23:17:18 volumio sudo[1454]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:18 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:19 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 10 23:17:19 volumio volumio[1176]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 23:17:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 23:17:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 10 23:17:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 23:17:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 23:17:19 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:19 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 23:17:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 23:17:19 volumio volumio[1176]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 23:17:19 volumio volumio[1176]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 23:17:19 volumio volumio[1176]: info: [1765405039447] CoreMusicLibrary::Adding element Last_100 Dec 10 23:17:19 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 23:17:19 volumio volumio[1176]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 23:17:19 volumio volumio[1176]: info: [1765405039562] CoreMusicLibrary::Adding element Webradio Dec 10 23:17:19 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 23:17:19 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 23:17:19 volumio sudo[1484]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 23:17:19 volumio sudo[1484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 23:17:19 volumio sudo[1485]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 10 23:17:19 volumio sudo[1484]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:19 volumio volumio[1176]: info: Initializing BBC Radios Dec 10 23:17:20 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 6. Dec 10 23:17:20 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 10 23:17:20 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 10 23:17:20 volumio sudo[1435]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:20 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 23:17:20 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:20 volumio volumio[1176]: info: Creating Spotify config file Dec 10 23:17:20 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:21 volumio ntpd[930]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Dec 10 23:17:21 volumio ntpd[930]: DNS: dns_check: DNS error: -11, System error Dec 10 23:17:21 volumio ntpd[930]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Dec 10 23:17:25 volumio volumio[1176]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 23:17:25 volumio volumio[1176]: info: [1765405045452] CoreMusicLibrary::Adding element YouTube Music Dec 10 23:17:25 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 23:17:25 volumio volumio[1176]: Cannot find translation for source YouTube Music Dec 10 23:17:25 volumio volumio[1176]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 10 23:17:25 volumio volumio[1176]: info: [1765405045713] CoreMusicLibrary::Adding element 80s80s Radio Dec 10 23:17:25 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 10 23:17:25 volumio volumio[1176]: Cannot find translation for source YouTube Music Dec 10 23:17:25 volumio volumio[1176]: Cannot find translation for source 80s80s Radio Dec 10 23:17:26 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 10 23:17:26 volumio sudo[1529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /tmp/mpd_oled_plugin.sh Dec 10 23:17:26 volumio sudo[1529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:26 volumio sudo[1531]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start mpd_oled_plugin.service Dec 10 23:17:26 volumio sudo[1531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:26 volumio sudo[1529]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:27 volumio volumio[1176]: info: Volumio Calling Home Dec 10 23:17:28 volumio volumio[1176]: info: Preparing to generate the ALSA configuration file Dec 10 23:17:29 volumio sudo[1538]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=4 pin_b=17 relative_axis=true steps-per-period=1 Dec 10 23:17:29 volumio sudo[1538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:29 volumio volumio[1176]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Dec 10 23:17:29 volumio volumio[1176]: info: Reading ALSA contributions from plugins. Dec 10 23:17:29 volumio volumio[1176]: info: [MPD_OLED Plugin] Set execute permissions on /tmp/mpd_oled_plugin.sh Dec 10 23:17:29 volumio volumio[1176]: info: MPD Permissions set Dec 10 23:17:29 volumio volumio[1176]: info: MPD Permissions set Dec 10 23:17:29 volumio volumio[1176]: info: Upmpdcli Daemon Started Dec 10 23:17:29 volumio volumio[1176]: info: [MPD_OLED Plugin] tmp script created /tmp/mpd_oled_plugin.sh Dec 10 23:17:29 volumio volumio[1176]: info: Spotify config file written Dec 10 23:17:29 volumio sudo[1538]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:29 volumio kernel: rotary-encoder rotary@4: gray Dec 10 23:17:29 volumio kernel: input: rotary@4 as /devices/platform/rotary@4/input/input0 Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio sudo[1555]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 10 23:17:30 volumio sudo[1555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:30 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 10 23:17:30 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 10 23:17:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 23:17:30 volumio go-librespot[1562]: go-librespot daemon starting... Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio sudo[1555]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:30 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:31 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:31 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:31 volumio volumio[1176]: info: No need to fix Spotify hosts Dec 10 23:17:31 volumio volumio[1176]: info: Starting Shairport Sync Dec 10 23:17:31 volumio volumio[1176]: info: Starting Shairport Sync Dec 10 23:17:31 volumio volumio[1176]: info: Starting Shairport Sync Dec 10 23:17:31 volumio go-librespot[1563]: time="2025-12-10T23:17:31+01:00" level=info msg="running go-librespot 0.4.0" Dec 10 23:17:31 volumio volumio[1176]: info: Asound.conf file unchanged, so no further update is needed Dec 10 23:17:31 volumio volumio[1176]: info: Output device has changed, restarting MPD Dec 10 23:17:31 volumio go-librespot[1563]: time="2025-12-10T23:17:31+01:00" level=debug msg="app state loaded" Dec 10 23:17:31 volumio go-librespot[1563]: time="2025-12-10T23:17:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 23:17:31 volumio sudo[1577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 23:17:31 volumio sudo[1577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:31 volumio sudo[1575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 23:17:31 volumio sudo[1575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:31 volumio volumio[1176]: info: Output device has changed, restarting Shairport Sync Dec 10 23:17:31 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:31 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:32 volumio sudo[1579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 23:17:32 volumio sudo[1579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:32 volumio sudo[1584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 23:17:32 volumio sudo[1584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:32 volumio mpd[1486]: 2025-12-10T23:17:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 10 23:17:32 volumio volumio[1176]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 10 23:17:32 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 10 23:17:32 volumio sudo[1440]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:32 volumio sudo[1450]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:32 volumio sudo[1582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 10 23:17:32 volumio sudo[1582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:32 volumio systemd[1]: Started mpd_oled_plugin.service - MPD OLED Plugin. Dec 10 23:17:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 10 23:17:32 volumio sudo[1531]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 10 23:17:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 23:17:32 volumio systemd[1]: shairport-sync.service: Consumed 2.146s CPU time. Dec 10 23:17:32 volumio sudo[1582]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 23:17:32 volumio sudo[1577]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:32 volumio sudo[1575]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:32 volumio sudo[1599]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-key gpio=27 active_low=1 gpio_pull=up keycode=20 Dec 10 23:17:32 volumio sudo[1599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 10 23:17:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 10 23:17:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 23:17:32 volumio systemd[1]: Stopping mpd_oled_plugin.service - MPD OLED Plugin... Dec 10 23:17:32 volumio volumio[1176]: Upnp client error: Error: This socket has been ended by the other party Dec 10 23:17:32 volumio sudo[1599]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 23:17:32 volumio kernel: input: button@1b as /devices/platform/button@1b/input/input1 Dec 10 23:17:32 volumio systemd[1]: mpd_oled_plugin.service: Deactivated successfully. Dec 10 23:17:32 volumio systemd[1]: Stopped mpd_oled_plugin.service - MPD OLED Plugin. Dec 10 23:17:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 10 23:17:32 volumio sudo[1579]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:33 volumio volumio[1176]: info: MPD Permissions set Dec 10 23:17:33 volumio volumio[1176]: info: [MPD_OLED Plugin] Started mpd_oled_plugin service Dec 10 23:17:33 volumio volumio[1176]: info: Shairport-Sync Started Dec 10 23:17:33 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 10 23:17:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 23:17:33 volumio systemd[1]: mpd.service: Consumed 10.421s CPU time. Dec 10 23:17:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 10 23:17:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 23:17:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 23:17:33 volumio volumio[1176]: Error adding Membership: Error: addMembership EINVAL Dec 10 23:17:33 volumio volumio[1176]: info: Shairport-Sync Started Dec 10 23:17:33 volumio volumio[1176]: info: Shairport-Sync Started Dec 10 23:17:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 23:17:33 volumio volumio[1176]: error: MPD error: Error: read ECONNRESET Dec 10 23:17:33 volumio volumio[1176]: error: MPD error: Error: read ECONNRESET Dec 10 23:17:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 23:17:34 volumio volumio[1176]: info: MPD running with PID1486 Dec 10 23:17:34 volumio volumio[1176]: ,establishing connection Dec 10 23:17:34 volumio sudo[1628]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 23:17:34 volumio sudo[1628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 23:17:34 volumio sudo[1628]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:34 volumio volumio[1176]: info: go-librespot daemon successfully initialized Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:34 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:34 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:35 volumio volumio[1176]: info: Starting Shairport Sync Dec 10 23:17:35 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:35 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:35 volumio volumio[1176]: info: CoreCommandRouter::volumioPause Dec 10 23:17:35 volumio volumio[1176]: info: CoreStateMachine::pause Dec 10 23:17:35 volumio volumio[1176]: info: mpdhttpout --- Volumio set on pause Dec 10 23:17:35 volumio volumio[1176]: info: mpdhttpout ---Configuration successfully added to mpd.conf. Dec 10 23:17:35 volumio sudo[1652]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Dec 10 23:17:35 volumio sudo[1652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:35 volumio sudo[1654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 10 23:17:35 volumio sudo[1654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:35 volumio sudo[1652]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 10 23:17:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 10 23:17:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 23:17:36 volumio systemd[1]: shairport-sync.service: Consumed 1.484s CPU time. Dec 10 23:17:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 10 23:17:36 volumio sudo[1654]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:36 volumio sudo[1662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 23:17:36 volumio sudo[1662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:36 volumio volumio[1176]: info: Shairport-Sync Started Dec 10 23:17:36 volumio sudo[1659]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Dec 10 23:17:36 volumio sudo[1659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:36 volumio sudo[1659]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:36 volumio volumio[1176]: info: Discovery: adding dc65ed2f-76bd-4411-8585-4254c32a2fd6 Dec 10 23:17:36 volumio volumio[1176]: info: Discovery: Found device Volumio Dec 10 23:17:36 volumio sudo[1664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 23:17:36 volumio sudo[1664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:36 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:36 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:37 volumio volumio[1176]: info: Discovery: this is already registered, dc65ed2f-76bd-4411-8585-4254c32a2fd6 Dec 10 23:17:37 volumio volumio[1176]: info: Discovery: Found device Volumio Dec 10 23:17:37 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:37 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:37 volumio volumio[1176]: info: Completed starting Core Plugins Dec 10 23:17:37 volumio volumio[1176]: info: ------------------------------------------- Dec 10 23:17:37 volumio volumio[1176]: info: ----- MyVolumio plugins startup ---- Dec 10 23:17:37 volumio volumio[1176]: info: ------------------------------------------- Dec 10 23:17:37 volumio volumio[1176]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 10 23:17:37 volumio volumio[1176]: info: Initializing connection to go-librespot Websocket Dec 10 23:17:38 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Dec 10 23:17:38 volumio sudo[1685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 23:17:38 volumio volumio[1176]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 10 23:17:38 volumio sudo[1685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:38 volumio volumio[1176]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 10 23:17:38 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 10 23:17:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 23:17:38 volumio systemd[1]: mpd.service: Consumed 4.194s CPU time. Dec 10 23:17:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 10 23:17:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 23:17:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 23:17:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 23:17:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 23:17:39 volumio sudo[1688]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 23:17:39 volumio sudo[1688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 23:17:39 volumio sudo[1688]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:39 volumio volumio[1176]: error: MPD error: Error: read ECONNRESET Dec 10 23:17:43 volumio go-librespot[1563]: time="2025-12-10T23:17:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 10 23:17:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 23:17:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 23:17:44 volumio mpd[1690]: 2025-12-10T23:17:44 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 10 23:17:44 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 10 23:17:44 volumio sudo[1584]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:44 volumio sudo[1685]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:44 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 10 23:17:44 volumio systemd[1]: Started mpd_oled_plugin.service - MPD OLED Plugin. Dec 10 23:17:44 volumio sudo[1662]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:44 volumio mpd_monitor.sh[1700]: MPD Monitor Service: Starting MPD Monitor Service Dec 10 23:17:44 volumio sudo[1664]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:45 volumio volumio[1176]: error: MPD error: The expression evaluated to a falsy value: Dec 10 23:17:45 volumio volumio[1176]: assert.ok(self.idling) Dec 10 23:17:45 volumio volumio[1176]: error: The expression evaluated to a falsy value: Dec 10 23:17:45 volumio volumio[1176]: assert.ok(self.idling) Dec 10 23:17:45 volumio volumio[1176]: error: MPD error: The expression evaluated to a falsy value: Dec 10 23:17:45 volumio volumio[1176]: assert.ok(self.idling) Dec 10 23:17:45 volumio volumio[1176]: error: The expression evaluated to a falsy value: Dec 10 23:17:45 volumio volumio[1176]: assert.ok(self.idling) Dec 10 23:17:45 volumio volumio[1176]: error: updateQueue error: null Dec 10 23:17:46 volumio volumio[1176]: info: Successfully started MPD Monitor Dec 10 23:17:46 volumio volumio[1176]: info: Successfully started MPD Monitor Dec 10 23:17:46 volumio volumio[1176]: error: MPD error: The expression evaluated to a falsy value: Dec 10 23:17:46 volumio volumio[1176]: assert.ok(self.idling) Dec 10 23:17:46 volumio volumio[1176]: error: The expression evaluated to a falsy value: Dec 10 23:17:46 volumio volumio[1176]: assert.ok(self.idling) Dec 10 23:17:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 10 23:17:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 23:17:46 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:46 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 23:17:46 volumio go-librespot[1719]: go-librespot daemon starting... Dec 10 23:17:46 volumio volumio[1176]: error: updateQueue error: null Dec 10 23:17:46 volumio go-librespot[1720]: time="2025-12-10T23:17:46+01:00" level=info msg="running go-librespot 0.4.0" Dec 10 23:17:46 volumio go-librespot[1720]: time="2025-12-10T23:17:46+01:00" level=debug msg="app state loaded" Dec 10 23:17:46 volumio go-librespot[1720]: time="2025-12-10T23:17:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 23:17:46 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:46 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:46 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:46 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:46 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:46 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:47 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:47 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:47 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:47 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:47 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:47 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:48 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:48 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:48 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:48 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:48 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:48 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:49 volumio volumio[1176]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io Dec 10 23:17:49 volumio sudo[1757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 23:17:49 volumio sudo[1757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:49 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:49 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:49 volumio sudo[1759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 23:17:49 volumio sudo[1759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:17:49 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 10 23:17:49 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 10 23:17:49 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 10 23:17:49 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:49 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:49 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 10 23:17:49 volumio sudo[1757]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:49 volumio mpd_monitor.sh[1762]: MPD Monitor Service: Starting MPD Monitor Service Dec 10 23:17:49 volumio volumio[1176]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 10 23:17:49 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 10 23:17:49 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 10 23:17:49 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 10 23:17:49 volumio volumio[1176]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.073&uuid=5310fef808ff7913fd032ea60f2074d9" http://updates.volumio.org/downloader-v1/track-device Dec 10 23:17:49 volumio volumio[1176]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 10 23:17:49 volumio volumio[1176]: Dload Upload Total Spent Left Speed Dec 10 23:17:49 volumio volumio[1176]: [1.0K blob data] Dec 10 23:17:49 volumio volumio[1176]: retrying in 5 seconds, trial 0 Dec 10 23:17:49 volumio volumio[1176]: info: Volumio Calling Home Dec 10 23:17:50 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 10 23:17:50 volumio mpd_monitor.sh[1772]: MPD Monitor Service: Starting MPD Monitor Service Dec 10 23:17:50 volumio sudo[1759]: pam_unix(sudo:session): session closed for user root Dec 10 23:17:50 volumio volumio[1176]: info: Successfully started MPD Monitor Dec 10 23:17:50 volumio volumio[1176]: info: Successfully started MPD Monitor Dec 10 23:17:50 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:50 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:50 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:50 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:50 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:50 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:51 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:51 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:51 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:51 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:51 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:51 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:52 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:52 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:52 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:52 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:52 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:52 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:52 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:52 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:53 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:53 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:53 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:53 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:54 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:54 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:54 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:54 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:54 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:54 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:54 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:54 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:55 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:55 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:55 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:55 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:55 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 10 23:17:55 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:55 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 10 23:17:55 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:55 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:55 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:55 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:56 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:56 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:56 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:56 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:56 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:56 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:57 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:57 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:57 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:57 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:57 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:57 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:57 volumio volumio[1176]: error: MyVolumio Plugin failed to start in a timely fashion Dec 10 23:17:57 volumio volumio[1176]: [Metrics] CommandRouter: 93s 336.08ms Dec 10 23:17:57 volumio volumio[1176]: info: CoreCommandRouter::volumiosetStartupVolume Dec 10 23:17:57 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 10 23:17:57 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 10 23:17:57 volumio volumio[1176]: info: CoreCommandRouter::Close All Modals sent Dec 10 23:17:58 volumio volumio[1176]: info: CoreCommandRouter::Close All Modals sent Dec 10 23:17:58 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:58 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:58 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:58 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:58 volumio go-librespot[1720]: time="2025-12-10T23:17:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 10 23:17:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 23:17:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 23:17:58 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:58 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:58 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:58 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:59 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 10 23:17:59 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 10 23:17:59 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 10 23:17:59 volumio volumio[1176]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Dec 10 23:17:59 volumio volumio[1176]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Dec 10 23:17:59 volumio volumio[1176]: aplay: xrun:1636: status error: Broken pipe Dec 10 23:17:59 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:59 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:17:59 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:17:59 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:00 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:00 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:00 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:00 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:00 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:00 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:01 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:01 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:01 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:01 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:01 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:01 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 10 23:18:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 23:18:01 volumio volumio[1176]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 23:18:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 23:18:01 volumio go-librespot[1923]: go-librespot daemon starting... Dec 10 23:18:02 volumio go-librespot[1926]: time="2025-12-10T23:18:02+01:00" level=info msg="running go-librespot 0.4.0" Dec 10 23:18:02 volumio go-librespot[1926]: time="2025-12-10T23:18:02+01:00" level=debug msg="app state loaded" Dec 10 23:18:02 volumio go-librespot[1926]: time="2025-12-10T23:18:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 23:18:03 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:03 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:03 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:03 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:03 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:03 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:04 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:04 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:04 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:04 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:04 volumio volumio[1176]: info: Initializing connection to go-librespot Websocket Dec 10 23:18:04 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:04 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:05 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:05 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:05 volumio volumio[1176]: info: BOOT COMPLETED Dec 10 23:18:05 volumio volumio[1176]: info: mpdhttpout ---Boot completed detected! Patching mpd now! Dec 10 23:18:05 volumio volumio[1176]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Dec 10 23:18:05 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:05 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:05 volumio volumio[1176]: info: CoreCommandRouter::volumioPause Dec 10 23:18:05 volumio volumio[1176]: info: CoreStateMachine::pause Dec 10 23:18:05 volumio volumio[1176]: info: mpdhttpout --- Volumio set on pause Dec 10 23:18:05 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:05 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:05 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:05 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:06 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:06 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:06 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:06 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:06 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:06 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:07 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:07 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:07 volumio volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Dec 10 23:18:07 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:07 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:08 volumio sudo[1992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 10 23:18:08 volumio sudo[1992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:18:08 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:08 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:08 volumio systemd[1]: Stopping mpd_oled_plugin.service - MPD OLED Plugin... Dec 10 23:18:08 volumio kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Dec 10 23:18:08 volumio kernel: ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110 Dec 10 23:18:08 volumio systemd[1]: mpd_oled_plugin.service: Deactivated successfully. Dec 10 23:18:08 volumio systemd[1]: Stopped mpd_oled_plugin.service - MPD OLED Plugin. Dec 10 23:18:08 volumio systemd[1]: mpd_oled_plugin.service: Consumed 1.201s CPU time. Dec 10 23:18:08 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 10 23:18:08 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 10 23:18:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 10 23:18:08 volumio systemd[1]: mpd.service: Consumed 5.618s CPU time. Dec 10 23:18:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 10 23:18:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 10 23:18:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 10 23:18:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 10 23:18:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 10 23:18:09 volumio sudo[2001]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 10 23:18:09 volumio sudo[2001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 10 23:18:09 volumio sudo[2001]: pam_unix(sudo:session): session closed for user root Dec 10 23:18:09 volumio bash[1240]: setdatetime-helper: all HTTPS Date fallbacks failed Dec 10 23:18:09 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 10 23:18:09 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 10 23:18:09 volumio systemd[1]: setdatetime-helper.service: Consumed 1.610s CPU time. Dec 10 23:18:09 volumio systemd[1]: Reached target multi-user.target - Multi-User System. Dec 10 23:18:09 volumio systemd[1]: Reached target graphical.target - Graphical Interface. Dec 10 23:18:09 volumio systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Dec 10 23:18:10 volumio systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Dec 10 23:18:10 volumio systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Dec 10 23:18:12 volumio volumio[1176]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.073&uuid=5310fef808ff7913fd032ea60f2074d9" http://updates.volumio.org/downloader-v1/track-device Dec 10 23:18:12 volumio volumio[1176]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 10 23:18:12 volumio volumio[1176]: Dload Upload Total Spent Left Speed Dec 10 23:18:12 volumio volumio[1176]: [1001B blob data] Dec 10 23:18:12 volumio volumio[1176]: retrying in 5 seconds, trial 1 Dec 10 23:18:12 volumio volumio[1176]: info: Volumio Calling Home Dec 10 23:18:14 volumio go-librespot[1926]: time="2025-12-10T23:18:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 10 23:18:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 23:18:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 23:18:14 volumio mpd[2003]: 2025-12-10T23:18:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 10 23:18:14 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 10 23:18:14 volumio sudo[1992]: pam_unix(sudo:session): session closed for user root Dec 10 23:18:14 volumio systemd[1]: Started mpd_oled_plugin.service - MPD OLED Plugin. Dec 10 23:18:14 volumio systemd[1]: Startup finished in 19.280s (kernel) + 2min 36.381s (userspace) = 2min 55.661s. Dec 10 23:18:14 volumio volumio[1176]: error: updateQueue error: null Dec 10 23:18:14 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:14 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:15 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:15 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:15 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:15 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:15 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:15 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:15 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:15 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:15 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:15 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:16 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:16 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:16 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:16 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:16 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:16 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:17 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:17 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 10 23:18:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 23:18:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 23:18:17 volumio go-librespot[2055]: go-librespot daemon starting... Dec 10 23:18:17 volumio go-librespot[2056]: time="2025-12-10T23:18:17+01:00" level=info msg="running go-librespot 0.4.0" Dec 10 23:18:17 volumio go-librespot[2056]: time="2025-12-10T23:18:17+01:00" level=debug msg="app state loaded" Dec 10 23:18:17 volumio go-librespot[2056]: time="2025-12-10T23:18:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 23:18:17 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:17 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:17 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:17 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:18 volumio sudo[2067]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 10 23:18:18 volumio sudo[2067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 10 23:18:18 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:18 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:18 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:18 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:18 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 10 23:18:18 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 10 23:18:18 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 10 23:18:18 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 10 23:18:18 volumio mpd_monitor.sh[2075]: MPD Monitor Service: Starting MPD Monitor Service Dec 10 23:18:18 volumio sudo[2067]: pam_unix(sudo:session): session closed for user root Dec 10 23:18:18 volumio volumio[1176]: info: Successfully started MPD Monitor Dec 10 23:18:19 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:19 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:19 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:19 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:19 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:19 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:19 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:19 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:20 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:20 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:20 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:20 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:20 volumio upmpdcli[2093]: writing RSA key Dec 10 23:18:21 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:21 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:21 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:21 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:21 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:21 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:21 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:21 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:22 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:22 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:22 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:22 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:22 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:22 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:22 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:22 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:23 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:23 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:23 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:23 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:23 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:23 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:23 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:23 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:24 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:24 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:24 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:24 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:25 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:25 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:25 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:25 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:25 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:25 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:25 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:25 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:26 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:26 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:26 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:26 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:26 volumio go-librespot[2056]: time="2025-12-10T23:18:26+01:00" level=debug msg="new websocket client" Dec 10 23:18:26 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:26 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:27 volumio volumio[1176]: info: Connection to go-librespot Websocket established Dec 10 23:18:27 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:27 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:27 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:27 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:27 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:27 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:27 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:27 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:28 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:28 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:28 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:28 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:28 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:28 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:29 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:29 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:29 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:29 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:29 volumio volumio[1176]: info: CoreCommandRouter::volumioGetState Dec 10 23:18:29 volumio volumio[1176]: info: CorePlayQueue::getTrack 0 Dec 10 23:18:29 volumio go-librespot[2056]: time="2025-12-10T23:18:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Dec 10 23:18:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 10 23:18:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 10 23:18:29 volumio volumio[1176]: info: Connection to go-librespot Websocket closed Dec 10 23:18:30 volumio volumio[1176]: info: Getting Spotify volume Dec 10 23:18:30 volumio volumio[1176]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 23:18:30 volumio volumio[1176]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 10 23:18:30 volumio volumio[1176]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 10 23:18:30 volumio volumio[1176]: errno: -111, Dec 10 23:18:30 volumio volumio[1176]: code: 'ECONNREFUSED', Dec 10 23:18:30 volumio volumio[1176]: syscall: 'connect', Dec 10 23:18:30 volumio volumio[1176]: address: '127.0.0.1', Dec 10 23:18:30 volumio volumio[1176]: port: 9879, Dec 10 23:18:30 volumio volumio[1176]: response: undefined Dec 10 23:18:30 volumio volumio[1176]: } Dec 10 23:18:30 volumio volumio[1176]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 10 23:18:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 10 23:18:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 10 23:18:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 10 23:18:33 volumio go-librespot[2220]: go-librespot daemon starting... Dec 10 23:18:33 volumio go-librespot[2221]: time="2025-12-10T23:18:33+01:00" level=info msg="running go-librespot 0.4.0" Dec 10 23:18:33 volumio go-librespot[2221]: time="2025-12-10T23:18:33+01:00" level=debug msg="app state loaded" Dec 10 23:18:33 volumio go-librespot[2221]: time="2025-12-10T23:18:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 10 23:18:42 volumio sudo[2246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-10 23:17' Dec 10 23:18:42 volumio sudo[2246]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"