May 30 22:08:33 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. May 30 22:08:33 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. May 30 22:08:33 volumio systemd[1]: setdatetime-helper.service: Consumed 1.484s CPU time. May 30 22:08:33 volumio ntpd[839]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 May 30 22:08:33 volumio ntpd[839]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 May 30 22:08:33 volumio ntpd[839]: DNS: Pool taking: 141.11.228.173 May 30 22:08:33 volumio ntpd[839]: DNS: Pool taking: 144.202.0.197 May 30 22:08:33 volumio ntpd[839]: DNS: Pool taking: 172.238.164.57 May 30 22:08:33 volumio ntpd[839]: DNS: Pool taking: 66.42.71.197 May 30 22:08:33 volumio ntpd[839]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 May 30 22:08:33 volumio winbindd[1099]: [2026/05/30 22:08:33.418207, 0] ../../source3/winbindd/winbindd.c:1440(main) May 30 22:08:33 volumio winbindd[1099]: winbindd version 4.17.8-Raspbian started. May 30 22:08:33 volumio winbindd[1099]: Copyright Andrew Tridgell and the Samba Team 1992-2022 May 30 22:08:33 volumio winbindd[1099]: [2026/05/30 22:08:33.438429, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) May 30 22:08:33 volumio winbindd[1099]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 30 22:08:33 volumio wireless.js[680]: WIRELESS.JS - INFO: Single Network Mode enabled (default) - only one network device can be active at a time between ethernet and wireless May 30 22:08:33 volumio systemd[1]: systemd-rfkill.service: Deactivated successfully. May 30 22:08:33 volumio systemd[1]: Started winbind.service - Samba Winbind Daemon. May 30 22:08:33 volumio systemd[1]: Starting smbd.service - Samba SMB Daemon... May 30 22:08:33 volumio wireless.js[680]: WIRELESS.JS - INFO: === SNM TRANSITION === May 30 22:08:33 volumio wireless.js[680]: WIRELESS.JS - INFO: Previous ethernet state: disconnected May 30 22:08:33 volumio wireless.js[680]: WIRELESS.JS - INFO: New ethernet state: connected May 30 22:08:33 volumio wireless.js[680]: WIRELESS.JS - INFO: Single Network Mode: enabled May 30 22:08:33 volumio wireless.js[680]: WIRELESS.JS - INFO: First start: yes May 30 22:08:33 volumio wireless.js[680]: WIRELESS.JS - INFO: Action: Switch to ethernet (WiFi scan mode) May 30 22:08:33 volumio wireless.js[680]: WIRELESS.JS - INFO: === END TRANSITION === May 30 22:08:33 volumio wireless.js[680]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow May 30 22:08:34 volumio ntpd[839]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 May 30 22:08:34 volumio ntpd[839]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 May 30 22:08:34 volumio ntpd[839]: DNS: Pool taking: 172.232.15.202 May 30 22:08:34 volumio ntpd[839]: DNS: Pool taking: 129.146.193.200 May 30 22:08:34 volumio ntpd[839]: DNS: Pool taking: 35.208.123.65 May 30 22:08:34 volumio ntpd[839]: DNS: Pool taking: 172.104.28.175 May 30 22:08:34 volumio ntpd[839]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 May 30 22:08:34 volumio smbd[1131]: [2026/05/30 22:08:34.464972, 0] ../../source3/smbd/server.c:1741(main) May 30 22:08:34 volumio smbd[1131]: smbd version 4.17.8-Raspbian started. May 30 22:08:34 volumio smbd[1131]: Copyright Andrew Tridgell and the Samba Team 1992-2022 May 30 22:08:34 volumio sudo[1141]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 30 22:08:34 volumio sudo[1141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 22:08:34 volumio sudo[1141]: pam_unix(sudo:session): session closed for user root May 30 22:08:34 volumio sudo[1143]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down May 30 22:08:34 volumio sudo[1143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 22:08:35 volumio sudo[1143]: pam_unix(sudo:session): session closed for user root May 30 22:08:35 volumio wireless.js[680]: WIRELESS.JS - INFO: Cleaning previous... May 30 22:08:35 volumio sudo[1146]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 30 22:08:35 volumio sudo[1146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 22:08:35 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 30 22:08:35 volumio sudo[1146]: pam_unix(sudo:session): session closed for user root May 30 22:08:35 volumio wireless.js[680]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations May 30 22:08:35 volumio wireless.js[680]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 5ms May 30 22:08:35 volumio wireless.js[680]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: b8:27:eb:85:ea:39) May 30 22:08:35 volumio sudo[1154]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get May 30 22:08:35 volumio sudo[1154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:08:35 volumio sudo[1154]: pam_unix(sudo:session): session closed for user root May 30 22:08:35 volumio sudo[1162]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan May 30 22:08:35 volumio sudo[1162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:08:35 volumio systemd[1]: Started smbd.service - Samba SMB Daemon. May 30 22:08:38 volumio sudo[1162]: pam_unix(sudo:session): session closed for user root May 30 22:08:38 volumio wireless.js[680]: WIRELESS.JS - INFO: SETTING APPROPRIATE REG DOMAIN: US May 30 22:08:38 volumio sudo[1172]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set US May 30 22:08:38 volumio sudo[1172]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:08:38 volumio sudo[1172]: pam_unix(sudo:session): session closed for user root May 30 22:08:38 volumio wireless.js[680]: WIRELESS.JS - INFO: SUCCESSFULLY SET NEW REGDOMAIN: US May 30 22:08:38 volumio wireless.js[680]: WIRELESS.JS - INFO: Single Network Mode: Ethernet active, maintaining WiFi scan capability May 30 22:08:38 volumio wireless.js[680]: WIRELESS.JS - INFO: SNM: Maintaining wlan0 UP without IP (scan mode) May 30 22:08:38 volumio wireless.js[680]: WIRELESS.JS - INFO: SNM: Users can configure WiFi via WebUI while ethernet is active May 30 22:08:39 volumio sudo[1181]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 30 22:08:39 volumio sudo[1181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 22:08:39 volumio sudo[1181]: pam_unix(sudo:session): session closed for user root May 30 22:08:39 volumio sudo[1184]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 30 22:08:39 volumio sudo[1184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 22:08:39 volumio sudo[1184]: pam_unix(sudo:session): session closed for user root May 30 22:08:39 volumio wpa_supplicant[1187]: Successfully initialized wpa_supplicant May 30 22:08:39 volumio ntpd[839]: CLOCK: time stepped by 0.333480 May 30 22:08:39 volumio ntpd[839]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes May 30 22:08:39 volumio wpa_supplicant[1187]: nl80211: kernel reports: Registration to specific type not supported May 30 22:08:39 volumio wpa_supplicant[1190]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all May 30 22:08:39 volumio wireless.js[680]: WIRELESS.JS - INFO: SNM: Transition to scan mode completed in 6073ms May 30 22:08:39 volumio wireless.js[680]: WIRELESS.JS - INFO: SNM: wlan0 is UP without IP, scan capable May 30 22:08:40 volumio wireless.js[680]: WIRELESS.JS - INFO: Notified systemd about wireless ready May 30 22:08:40 volumio systemd[1]: Started wireless.service - Wireless Services. May 30 22:08:40 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 30 22:08:40 volumio systemd[1]: Started volumio.service - Volumio Backend Module. May 30 22:08:40 volumio systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... May 30 22:08:40 volumio systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. May 30 22:08:40 volumio systemd[1]: Received SIGRTMIN+21 from PID 295 (plymouthd). May 30 22:08:40 volumio volumio-cpu-tweak[1208]: Setting RT Priority for mpd May 30 22:08:40 volumio volumio-cpu-tweak[1222]: pid 35's current scheduling policy: SCHED_OTHER May 30 22:08:40 volumio volumio-cpu-tweak[1222]: pid 35's current scheduling priority: 0 May 30 22:08:40 volumio volumio-cpu-tweak[1208]: Setting MPD Affinity May 30 22:08:40 volumio volumio-cpu-tweak[1223]: pid 3's current affinity mask: f May 30 22:08:40 volumio volumio-cpu-tweak[1208]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input May 30 22:08:40 volumio volumio-cpu-tweak[1208]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance May 30 22:08:40 volumio systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. May 30 22:08:40 volumio systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. May 30 22:08:40 volumio systemd[1]: Received SIGRTMIN+21 from PID 295 (plymouthd). May 30 22:08:40 volumio volumio-remote-updater[679]: [2026-05-30 22:08:40] [info] asio async_connect error: asio.system:111 (Connection refused) May 30 22:08:40 volumio volumio-remote-updater[679]: [2026-05-30 22:08:40] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) May 30 22:08:40 volumio volumio-remote-updater[679]: [2026-05-30 22:08:40] [error] handle_connect error: Connection refused May 30 22:08:40 volumio systemd[1]: Started getty@tty1.service - Getty on tty1. May 30 22:08:40 volumio systemd[1]: Reached target getty.target - Login Prompts. May 30 22:08:40 volumio systemd[1]: Reached target multi-user.target - Multi-User System. May 30 22:08:40 volumio systemd[1]: Reached target graphical.target - Graphical Interface. May 30 22:08:40 volumio systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... May 30 22:08:40 volumio systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. May 30 22:08:40 volumio systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. May 30 22:08:40 volumio systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. May 30 22:08:40 volumio systemd[1]: Startup finished in 19.194s (kernel) + 18.932s (userspace) = 38.126s. May 30 22:08:43 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. May 30 22:08:43 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 22:08:43 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 22:08:43 volumio upmpdcli[1229]: Could not open config: /tmp/upmpdcli.conf May 30 22:08:43 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 30 22:08:43 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 30 22:08:44 volumio volumio[1206]: info: ------------------------------------------- May 30 22:08:44 volumio volumio[1206]: info: ----- Volumio3 ---- May 30 22:08:44 volumio volumio[1206]: info: ------------------------------------------- May 30 22:08:44 volumio volumio[1206]: info: ----- System startup ---- May 30 22:08:44 volumio volumio[1206]: info: ------------------------------------------- May 30 22:08:46 volumio volumio[1206]: info: MYVOLUMIO Environment detected May 30 22:08:46 volumio volumio[1206]: info: Plugin folders cleanup May 30 22:08:46 volumio volumio[1206]: info: Scanning into folder /volumio/app/plugins/ May 30 22:08:46 volumio volumio[1206]: info: Scanning category audio_interface May 30 22:08:46 volumio volumio[1206]: info: Scanning category miscellanea May 30 22:08:46 volumio volumio[1206]: info: Scanning category music_service May 30 22:08:46 volumio volumio[1206]: info: Scanning category plugins.json May 30 22:08:46 volumio volumio[1206]: info: Scanning category system_controller May 30 22:08:46 volumio volumio[1206]: info: Scanning category user_interface May 30 22:08:46 volumio volumio[1206]: info: Scanning into folder /data/plugins/ May 30 22:08:46 volumio volumio[1206]: info: Scanning category music_service May 30 22:08:46 volumio volumio[1206]: info: Scanning category system_hardware May 30 22:08:46 volumio volumio[1206]: info: Scanning category user_interface May 30 22:08:46 volumio volumio[1206]: info: Plugin folders cleanup completed May 30 22:08:46 volumio volumio[1206]: info: ------------------------------------------- May 30 22:08:46 volumio volumio[1206]: info: ----- Core plugins startup ---- May 30 22:08:46 volumio volumio[1206]: info: ------------------------------------------- May 30 22:08:46 volumio volumio[1206]: info: Loading plugins from folder /volumio/app/plugins/ May 30 22:08:46 volumio volumio[1206]: info: Adding plugin upnp to MyMusic Plugins May 30 22:08:46 volumio volumio[1206]: info: Adding plugin airplay_emulation to MyMusic Plugins May 30 22:08:46 volumio volumio[1206]: info: Adding plugin upnp_browser to MyMusic Plugins May 30 22:08:46 volumio volumio[1206]: info: Loading plugins from folder /data/plugins/ May 30 22:08:46 volumio volumio[1206]: info: Loading plugin "system"... May 30 22:08:46 volumio volumio[1206]: info: Loading plugin "appearance"... May 30 22:08:48 volumio volumio[1206]: info: Loading plugin "network"... May 30 22:08:48 volumio volumio[1206]: info: Refreshing Cached IP Addresses May 30 22:08:48 volumio sudo[1244]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 30 22:08:48 volumio sudo[1244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:08:48 volumio sudo[1244]: pam_unix(sudo:session): session closed for user root May 30 22:08:48 volumio volumio[1206]: info: Loading plugin "services"... May 30 22:08:48 volumio sudo[1254]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 30 22:08:48 volumio sudo[1254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:08:48 volumio volumio[1206]: info: Loading plugin "volumio5onboarding"... May 30 22:08:49 volumio sudo[1245]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 30 22:08:49 volumio sudo[1245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:08:49 volumio volumio[1206]: info: Loading plugin "alsa_controller"... May 30 22:08:49 volumio sudo[1245]: pam_unix(sudo:session): session closed for user root May 30 22:08:49 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 22:08:49 volumio volumio[1206]: info: Loading plugin "wizard"... May 30 22:08:49 volumio volumio[1206]: info: Loading plugin "networkfs"... May 30 22:08:49 volumio volumio[1206]: info: Starting Udev Watcher for removable devices May 30 22:08:49 volumio volumio[1206]: info: Ignoring mount for partition: boot May 30 22:08:49 volumio volumio[1206]: info: Ignoring mount for partition: volumio May 30 22:08:49 volumio volumio[1206]: info: Ignoring mount for partition: volumio_data May 30 22:08:49 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 30 22:08:49 volumio volumio[1206]: info: Loading plugin "pi_screen_setup"... May 30 22:08:50 volumio volumio-remote-updater[679]: [2026-05-30 22:08:50] [connect] Successful connection May 30 22:08:51 volumio volumio[1206]: info: Loading plugin "volumio_command_line_client"... May 30 22:08:51 volumio volumio[1206]: info: Loading plugin "upnp"... May 30 22:08:51 volumio volumio[1206]: info: [1780200531430] Starting Upmpd Daemon May 30 22:08:51 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 30 22:08:51 volumio volumio[1206]: info: Loading plugin "my_music"... May 30 22:08:51 volumio volumio[1206]: info: Loading plugin "mpd"... May 30 22:08:51 volumio sudo[1254]: pam_unix(sudo:session): session closed for user root May 30 22:08:52 volumio volumio[1206]: info: Loading plugin "upnp_browser"... May 30 22:08:53 volumio login[1226]: pam_unix(login:session): session opened for user volumio(uid=1000) by LOGIN(uid=0) May 30 22:08:53 volumio systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. May 30 22:08:53 volumio systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... May 30 22:08:53 volumio systemd-logind[672]: New session 1 of user volumio. May 30 22:08:53 volumio systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. May 30 22:08:53 volumio systemd[1]: Starting user@1000.service - User Manager for UID 1000... May 30 22:08:53 volumio (systemd)[1287]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) May 30 22:08:54 volumio systemd[1287]: Queued start job for default target default.target. May 30 22:08:54 volumio systemd[1287]: Created slice app.slice - User Application Slice. May 30 22:08:54 volumio systemd[1287]: Reached target paths.target - Paths. May 30 22:08:54 volumio systemd[1287]: Reached target timers.target - Timers. May 30 22:08:54 volumio systemd[1287]: Listening on dirmngr.socket - GnuPG network certificate management daemon. May 30 22:08:54 volumio systemd[1287]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). May 30 22:08:54 volumio systemd[1287]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). May 30 22:08:54 volumio systemd[1287]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). May 30 22:08:54 volumio systemd[1287]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. May 30 22:08:54 volumio systemd[1287]: Reached target sockets.target - Sockets. May 30 22:08:54 volumio systemd[1287]: Reached target basic.target - Basic System. May 30 22:08:54 volumio systemd[1]: Started user@1000.service - User Manager for UID 1000. May 30 22:08:54 volumio systemd[1287]: Started mpris-proxy.service - Bluetooth mpris proxy. May 30 22:08:54 volumio systemd[1287]: Reached target default.target - Main User Target. May 30 22:08:54 volumio systemd[1]: Started session-1.scope - Session 1 of User volumio. May 30 22:08:54 volumio systemd[1287]: Startup finished in 820ms. May 30 22:08:54 volumio mpris-proxy[1302]: Can't get on session bus May 30 22:08:54 volumio systemd[1287]: mpris-proxy.service: Main process exited, code=exited, status=1/FAILURE May 30 22:08:54 volumio systemd[1287]: mpris-proxy.service: Failed with result 'exit-code'. May 30 22:08:54 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. May 30 22:08:55 volumio volumio[1206]: info: Starting UPNP Browser May 30 22:08:55 volumio volumio[1206]: info: Loading plugin "alarm-clock"... May 30 22:08:55 volumio volumio[1206]: info: Loading plugin "airplay_emulation"... May 30 22:08:55 volumio volumio[1206]: info: Starting Shairport Sync May 30 22:08:55 volumio volumio[1206]: info: Loading plugin "last_100"... May 30 22:08:55 volumio volumio[1206]: info: Loading plugin "webradio"... May 30 22:08:55 volumio volumio[1206]: info: Loading plugin "i2s_dacs"... May 30 22:08:55 volumio volumio[1206]: info: Loading plugin "volumiodiscovery"... May 30 22:08:55 volumio volumio[1206]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 30 22:08:55 volumio volumio[1206]: *** WARNING *** Please fix your application to use the native API of Avahi! May 30 22:08:55 volumio node[1206]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 30 22:08:55 volumio volumio[1206]: *** WARNING *** For more information see May 30 22:08:55 volumio volumio[1206]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 30 22:08:55 volumio volumio[1206]: *** WARNING *** Please fix your application to use the native API of Avahi! May 30 22:08:55 volumio volumio[1206]: *** WARNING *** For more information see May 30 22:08:55 volumio node[1206]: *** WARNING *** Please fix your application to use the native API of Avahi! May 30 22:08:55 volumio node[1206]: *** WARNING *** For more information see May 30 22:08:55 volumio node[1206]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 30 22:08:55 volumio node[1206]: *** WARNING *** Please fix your application to use the native API of Avahi! May 30 22:08:55 volumio node[1206]: *** WARNING *** For more information see May 30 22:08:55 volumio volumio[1206]: info: Applying required configuration parameters for plugin volumiodiscovery May 30 22:08:55 volumio volumio[1206]: info: Discovery: Started advertising with name: Volumio May 30 22:08:55 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 30 22:08:55 volumio volumio[1206]: info: Loading plugin "spop"... May 30 22:08:58 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. May 30 22:08:58 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 22:08:58 volumio volumio[1206]: info: Loading plugin "peppy_screensaver"... May 30 22:08:58 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 22:08:58 volumio upmpdcli[1308]: Could not open config: /tmp/upmpdcli.conf May 30 22:08:58 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 30 22:08:58 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 30 22:09:00 volumio volumio[1206]: info: Applying required configuration parameters for plugin peppy_screensaver May 30 22:09:00 volumio volumio[1206]: info: Loading plugin "outputs"... May 30 22:09:00 volumio volumio[1206]: info: Loading plugin "albumart"... May 30 22:09:00 volumio volumio[1206]: info: Plugin example_plugin is not enabled May 30 22:09:00 volumio volumio[1206]: info: Loading plugin "inputs"... May 30 22:09:00 volumio volumio[1206]: info: Loading plugin "updater_comm"... May 30 22:09:00 volumio volumio[1206]: info: Plugin mpdemulation is not enabled May 30 22:09:00 volumio volumio[1206]: info: Loading plugin "rest_api"... May 30 22:09:00 volumio volumio[1206]: info: Loading plugin "websocket"... May 30 22:09:00 volumio volumio[1206]: info: Starting Socket.io Server version 1.7.4 May 30 22:09:00 volumio volumio[1206]: info: Loading i18n strings for locale es May 30 22:09:00 volumio volumio[1206]: Updating browse sources language May 30 22:09:00 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::initPlayerControls May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 22:09:01 volumio volumio[1323]: Forking 3 albumart workers May 30 22:09:01 volumio volumio[1206]: Express server listening on port 3000 May 30 22:09:01 volumio volumio[1206]: [Metrics] WebUI: 18s 290.44ms May 30 22:09:01 volumio volumio[1206]: info: CoreStateMachine::resetVolumioState May 30 22:09:01 volumio volumio[1206]: info: CoreStateMachine::getcurrentVolume May 30 22:09:01 volumio volumio[1206]: info: CoreCommandRouter::volumioRetrievevolume May 30 22:09:01 volumio volumio[1206]: info: Cannot read play queue from file May 30 22:09:01 volumio sudo[1354]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 30 22:09:01 volumio sudo[1354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:01 volumio sudo[1354]: pam_unix(sudo:session): session closed for user root May 30 22:09:01 volumio sudo[1361]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 30 22:09:01 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. May 30 22:09:01 volumio volumio[1206]: info: Volumio Network Manager: Network status updated: 1 May 30 22:09:01 volumio sudo[1361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:01 volumio sudo[1361]: pam_unix(sudo:session): session closed for user root May 30 22:09:02 volumio volumio[1206]: info: VolumeController:: Volume=100 Mute =false May 30 22:09:02 volumio volumio[1206]: info: CoreStateMachine::pushState May 30 22:09:02 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:02 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 22:09:02 volumio volumio[1206]: info: CoreCommandRouter::volumioPushState May 30 22:09:02 volumio volumio[1206]: info: CoreStateMachine::updateTrackBlock May 30 22:09:02 volumio volumio[1206]: info: CorePlayQueue::getTrackBlock May 30 22:09:02 volumio volumio[1206]: info: CoreCommandRouter::volumioRetrievevolume May 30 22:09:02 volumio volumio[1206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 May 30 22:09:02 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 22:09:03 volumio volumio[1206]: info: CoreStateMachine::setRepeat null single undefined May 30 22:09:03 volumio volumio[1206]: info: CoreStateMachine::pushState May 30 22:09:03 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:03 volumio volumio[1206]: info: CoreCommandRouter::volumioPushState May 30 22:09:03 volumio volumio[1206]: info: CoreStateMachine::setRandom null May 30 22:09:03 volumio volumio[1206]: info: CoreStateMachine::pushState May 30 22:09:03 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:03 volumio volumio[1206]: info: CoreCommandRouter::volumioPushState May 30 22:09:03 volumio volumio[1206]: info: Setting Device type: Raspberry PI May 30 22:09:03 volumio volumio[1206]: info: VolumeController:: Volume=100 Mute =false May 30 22:09:03 volumio volumio[1206]: info: CoreStateMachine::pushState May 30 22:09:03 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:03 volumio volumio[1206]: info: CoreCommandRouter::volumioPushState May 30 22:09:03 volumio sudo[1389]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 30 22:09:03 volumio sudo[1389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:03 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... May 30 22:09:03 volumio volumio[1206]: info: Completed loading Core Plugins May 30 22:09:03 volumio volumio[1206]: info: Preparing to generate the ALSA configuration file May 30 22:09:04 volumio volumio[1206]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf May 30 22:09:04 volumio volumio[1206]: info: Reading ALSA contributions from plugins. May 30 22:09:04 volumio volumio[1206]: info: Asound.conf file unchanged, so no further update is needed May 30 22:09:04 volumio volumio[1206]: info: Output device has changed, restarting MPD May 30 22:09:04 volumio volumio[1206]: info: Output device has changed, restarting Shairport Sync May 30 22:09:04 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:04 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 22:09:04 volumio sudo[1403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 30 22:09:04 volumio sudo[1403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:04 volumio sudo[1403]: pam_unix(sudo:session): session closed for user root May 30 22:09:04 volumio sudo[1407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 30 22:09:04 volumio sudo[1407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:04 volumio volumio[1206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 30 22:09:04 volumio volumio[1206]: info: ___________ START PLUGINS ___________ May 30 22:09:04 volumio volumio[1206]: info: pi_screen_setup: Starting plugin May 30 22:09:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 30 22:09:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 30 22:09:04 volumio sudo[1416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service May 30 22:09:04 volumio sudo[1416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:04 volumio volumio[1206]: info: pi_screen_setup: Loaded bundled presets v1.5.9 May 30 22:09:04 volumio volumio[1206]: info: pi_screen_setup: Active presets source: bundled, 231 presets loaded May 30 22:09:04 volumio volumio[1206]: info: pi_screen_setup: Detected model: Raspberry Pi 3 Model B Plus Rev 1.3 May 30 22:09:04 volumio volumio[1206]: info: pi_screen_setup: Detected SoC: bcm2837 May 30 22:09:04 volumio volumio[1206]: info: pi_screen_setup: Detected RAM: 870 MB May 30 22:09:04 volumio volumio[1206]: info: pi_screen_setup: Hardware detection complete - {"model":"Pi 3","model_raw":"Raspberry Pi 3 Model B Plus Rev 1.3","soc":"bcm2837","ram_mb":870,"hdmi_ports":1,"dsi_ports":["dsi0"],"has_composite":true,"kms_supported":true,"kms_overlay":"vc4-kms-v3d","is_pi":true} May 30 22:09:04 volumio volumio[1206]: info: ControllerMpd::onStart: Initializing MPD May 30 22:09:04 volumio volumio[1206]: info: Creating MPD Configuration file May 30 22:09:04 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 22:09:04 volumio volumio[1206]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 30 22:09:04 volumio volumio[1206]: info: [1780200544981] CoreMusicLibrary::Adding element Media Servers May 30 22:09:04 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 22:09:04 volumio sudo[1422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 30 22:09:04 volumio sudo[1422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:05 volumio sudo[1422]: pam_unix(sudo:session): session closed for user root May 30 22:09:05 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. May 30 22:09:05 volumio sudo[1416]: pam_unix(sudo:session): session closed for user root May 30 22:09:05 volumio volumio[1206]: info: UPNP Browser: Client initialized successfully May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 22:09:05 volumio volumio[1206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 30 22:09:05 volumio sudo[1424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 22:09:05 volumio sudo[1424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:05 volumio systemd[1]: mpd.service: Deactivated successfully. May 30 22:09:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 30 22:09:05 volumio systemd[1]: mpd.socket: Deactivated successfully. May 30 22:09:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 30 22:09:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 30 22:09:05 volumio volumio-remote-updater[679]: [2026-05-30 22:09:05] [connect] Successful connection May 30 22:09:05 volumio volumio[1206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 30 22:09:05 volumio volumio[1206]: info: [1780200545381] CoreMusicLibrary::Adding element Last_100 May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 30 22:09:05 volumio volumio[1206]: info: [1780200545398] CoreMusicLibrary::Adding element Webradio May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 22:09:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 30 22:09:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 22:09:05 volumio volumio[1206]: info: Initializing BBC Radios May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 22:09:05 volumio volumio[1206]: info: Creating Spotify config file May 30 22:09:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:05 volumio volumio[1206]: info: Loading i18n strings for locale es May 30 22:09:05 volumio volumio[1206]: info: /tmp/myfifo created May 30 22:09:05 volumio volumio[1206]: info: /tmp/myfifosa created May 30 22:09:06 volumio sudo[1461]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 May 30 22:09:06 volumio sudo[1461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:06 volumio sudo[1461]: pam_unix(sudo:session): session closed for user root May 30 22:09:06 volumio volumio[1206]: info: snd-dummy loaded May 30 22:09:06 volumio systemd[1287]: Reached target sound.target - Sound Card. May 30 22:09:06 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 22:09:06 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:06 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:06 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startShairportSync May 30 22:09:06 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:06 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 22:09:07 volumio volumio[1206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 30 22:09:07 volumio volumio5-onboarding[1421]: time=2026-05-30T22:09:07.123-06:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z May 30 22:09:07 volumio volumio[1206]: info: Volumio Calling Home May 30 22:09:07 volumio sudo[1436]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 30 22:09:07 volumio sudo[1436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 22:09:07 volumio volumio[1206]: info: pi_screen_setup: Detected prior configuration (backup=true, banner=true) - restoring wizard_complete May 30 22:09:07 volumio sudo[1492]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory May 30 22:09:07 volumio volumio[1206]: info: pi_screen_setup: Boot validation - {"valid":true,"drift_detected":false,"missing_videoconfig":false,"missing_include":false,"config_mismatch":false,"volumioconfig_mismatch":false,"errors":[]} May 30 22:09:07 volumio sudo[1436]: pam_unix(sudo:session): session closed for user root May 30 22:09:07 volumio sudo[1487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/shairport-sync.conf.tmpl /volumio/app/plugins/music_service/airplay_emulation/shairport-sync.conf.tmpl May 30 22:09:07 volumio sudo[1487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:07 volumio sudo[1487]: pam_unix(sudo:session): session closed for user root May 30 22:09:07 volumio volumio[1333]: Starting albumart workers May 30 22:09:07 volumio volumio[1206]: info: pi_screen_setup: Management server started on port 4567 May 30 22:09:09 volumio volumio[1335]: Starting albumart workers May 30 22:09:09 volumio volumio[1336]: Starting albumart workers May 30 22:09:11 volumio volumio[1206]: info: Discovery: adding d5fd69cf-c5fd-4af8-926a-545914832c3a May 30 22:09:11 volumio volumio[1206]: info: Discovery: Found device Volumio May 30 22:09:11 volumio volumio[1206]: info: CoreCommandRouter::volumioGetState May 30 22:09:11 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:11 volumio volumio[1206]: info: Discovery: this is already registered, d5fd69cf-c5fd-4af8-926a-545914832c3a May 30 22:09:11 volumio volumio[1206]: info: Discovery: Found device Volumio May 30 22:09:11 volumio volumio[1206]: info: CoreCommandRouter::volumioGetState May 30 22:09:11 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:11 volumio volumio[1206]: info: MPD Permissions set May 30 22:09:11 volumio volumio[1206]: info: MPD Permissions set May 30 22:09:11 volumio volumio[1206]: info: Volumio called home May 30 22:09:11 volumio sudo[1522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl May 30 22:09:11 volumio sudo[1522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:11 volumio volumio[1206]: info: Spotify config file written May 30 22:09:11 volumio sudo[1522]: pam_unix(sudo:session): session closed for user root May 30 22:09:12 volumio sudo[1525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 30 22:09:12 volumio sudo[1525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:12 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. May 30 22:09:12 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. May 30 22:09:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 30 22:09:12 volumio sudo[1525]: pam_unix(sudo:session): session closed for user root May 30 22:09:12 volumio go-librespot[1527]: go-librespot daemon starting... May 30 22:09:12 volumio volumio[1206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:12 volumio volumio[1206]: info: No need to fix Spotify hosts May 30 22:09:13 volumio volumio[1206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 May 30 22:09:13 volumio volumio[1206]: info: Received Get System Info May 30 22:09:13 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 22:09:13 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 22:09:13 volumio volumio[1206]: info: Discovery: Getting this device information May 30 22:09:13 volumio volumio[1206]: info: CoreCommandRouter::volumioGetState May 30 22:09:13 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:13 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 22:09:13 volumio volumio5-onboarding[1421]: time=2026-05-30T22:09:13.559-06:00 level=INFO msg="system info for 5ae242cf5b171bc18cf9ec366d256e92" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 May 30 22:09:13 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , createMPDFile May 30 22:09:13 volumio go-librespot[1530]: time="2026-05-30T22:09:13-06:00" level=info msg="running go-librespot 0.7.1" May 30 22:09:13 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. May 30 22:09:13 volumio go-librespot[1530]: time="2026-05-30T22:09:13-06:00" level=debug msg="app state loaded" May 30 22:09:13 volumio go-librespot[1530]: time="2026-05-30T22:09:13-06:00" level=debug msg="stored credentials not found" May 30 22:09:13 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 30 22:09:13 volumio go-librespot[1530]: time="2026-05-30T22:09:13-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 30 22:09:13 volumio sudo[1554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 30 22:09:13 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 30 22:09:13 volumio sudo[1389]: pam_unix(sudo:session): session closed for user root May 30 22:09:14 volumio sudo[1554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:14 volumio volumio[1206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 30 22:09:14 volumio sudo[1554]: pam_unix(sudo:session): session closed for user root May 30 22:09:14 volumio volumio[1206]: info: MPD Permissions set May 30 22:09:14 volumio volumio[1206]: info: Upmpdcli Daemon Started May 30 22:09:14 volumio volumio[1206]: info: Starting Shairport Sync May 30 22:09:14 volumio volumio[1206]: info: Starting Shairport Sync May 30 22:09:14 volumio volumio[1206]: info: Starting Shairport Sync May 30 22:09:14 volumio sudo[1565]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 30 22:09:14 volumio sudo[1565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:14 volumio volumio[1206]: info: Starting Shairport Sync May 30 22:09:14 volumio sudo[1570]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 30 22:09:14 volumio sudo[1570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:14 volumio sudo[1567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 30 22:09:14 volumio sudo[1567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 30 22:09:14 volumio sudo[1572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 30 22:09:14 volumio sudo[1572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 30 22:09:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 30 22:09:14 volumio systemd[1]: shairport-sync.service: Consumed 1.684s CPU time. May 30 22:09:14 volumio sudo[1577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 30 22:09:14 volumio sudo[1577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 22:09:14 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 22:09:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 30 22:09:14 volumio sudo[1565]: pam_unix(sudo:session): session closed for user root May 30 22:09:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 30 22:09:14 volumio sudo[1572]: pam_unix(sudo:session): session closed for user root May 30 22:09:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 30 22:09:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 30 22:09:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 30 22:09:14 volumio sudo[1570]: pam_unix(sudo:session): session closed for user root May 30 22:09:14 volumio systemd[1]: mpd.service: Deactivated successfully. May 30 22:09:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 30 22:09:14 volumio systemd[1]: mpd.service: Consumed 1.400s CPU time. May 30 22:09:14 volumio systemd[1]: mpd.socket: Deactivated successfully. May 30 22:09:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 30 22:09:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 30 22:09:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 30 22:09:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 30 22:09:14 volumio sudo[1567]: pam_unix(sudo:session): session closed for user root May 30 22:09:14 volumio volumio[1206]: info: Shairport-Sync Started May 30 22:09:14 volumio volumio[1206]: Error adding Membership: Error: addMembership EINVAL May 30 22:09:14 volumio volumio[1206]: info: Shairport-Sync Started May 30 22:09:14 volumio volumio[1206]: info: Shairport-Sync Started May 30 22:09:14 volumio volumio[1206]: info: Shairport-Sync Started May 30 22:09:15 volumio volumio[1206]: info: CoreCommandRouter::volumioGetState May 30 22:09:15 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:15 volumio volumio[1206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 30 22:09:15 volumio sudo[1592]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 30 22:09:15 volumio sudo[1592]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 22:09:15 volumio sudo[1616]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory May 30 22:09:15 volumio sudo[1592]: pam_unix(sudo:session): session closed for user root May 30 22:09:16 volumio volumio[1206]: info: go-librespot daemon successfully initialized May 30 22:09:18 volumio volumio5-onboarding[1421]: time=2026-05-30T22:09:18.602-06:00 level=INFO msg="bootstrapping state" hasInternet=false May 30 22:09:18 volumio volumio[1206]: info: Received Get System Info May 30 22:09:18 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 22:09:18 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 22:09:18 volumio volumio[1206]: info: Discovery: Getting this device information May 30 22:09:18 volumio volumio[1206]: info: CoreCommandRouter::volumioGetState May 30 22:09:18 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:18 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 22:09:18 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 30 22:09:18 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 30 22:09:18 volumio volumio5-onboarding[1421]: time=2026-05-30T22:09:18.647-06:00 level=INFO msg="enabling local network discovery" May 30 22:09:18 volumio volumio5-onboarding[1421]: time=2026-05-30T22:09:18.682-06:00 level=INFO msg="enabling BLE discovery" May 30 22:09:19 volumio volumio[1206]: info: Initializing connection to go-librespot Websocket May 30 22:09:19 volumio go-librespot[1530]: time="2026-05-30T22:09:19-06:00" level=debug msg="new websocket client" May 30 22:09:19 volumio volumio[1206]: info: Connection to go-librespot Websocket established May 30 22:09:19 volumio volumio5-onboarding[1421]: time=2026-05-30T22:09:19.974-06:00 level=INFO msg="service successfully established" component=discovery/localnet May 30 22:09:20 volumio volumio-remote-updater[679]: [2026-05-30 22:09:20] [connect] Successful connection May 30 22:09:20 volumio volumio-remote-updater[679]: [2026-05-30 22:09:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1780200560 101 May 30 22:09:20 volumio volumio[1206]: 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: 5 May 30 22:09:23 volumio volumio[1206]: info: Getting Spotify volume May 30 22:09:23 volumio volumio[1206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 May 30 22:09:23 volumio volumio[1206]: info: CoreCommandRouter::volumioGetState May 30 22:09:23 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:23 volumio volumio[1206]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 22:09:23 volumio volumio[1206]: SPOTIFY: SPOTIFY VOLUME undefined May 30 22:09:23 volumio volumio[1206]: SPOTIFY: VOLUMIO VOLUME 100 May 30 22:09:23 volumio volumio[1206]: info: Aligning Spotify Volume to Volumio Volume May 30 22:09:23 volumio volumio[1206]: info: CoreCommandRouter::volumioGetState May 30 22:09:23 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 May 30 22:09:23 volumio volumio[1206]: info: Setting Spotify Volume from Volumio: 100 May 30 22:09:24 volumio go-librespot[1530]: time="2026-05-30T22:09:24-06:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": net/http: TLS handshake timeout" May 30 22:09:24 volumio volumio[1206]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 22:09:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 30 22:09:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 30 22:09:24 volumio volumio[1206]: Error: socket hang up May 30 22:09:24 volumio volumio[1206]: at connResetException (node:internal/errors:720:14) May 30 22:09:24 volumio volumio[1206]: at Socket.socketOnEnd (node:_http_client:519:23) May 30 22:09:24 volumio volumio[1206]: at Socket.emit (node:events:526:35) May 30 22:09:24 volumio volumio[1206]: at endReadableNT (node:internal/streams/readable:1376:12) May 30 22:09:24 volumio volumio[1206]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { May 30 22:09:24 volumio volumio[1206]: code: 'ECONNRESET', May 30 22:09:24 volumio volumio[1206]: response: undefined May 30 22:09:24 volumio volumio[1206]: } May 30 22:09:24 volumio volumio[1206]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 22:09:27 volumio mpd[1617]: 2026-05-30T22:09:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 30 22:09:27 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 30 22:09:27 volumio sudo[1407]: pam_unix(sudo:session): session closed for user root May 30 22:09:27 volumio sudo[1577]: pam_unix(sudo:session): session closed for user root May 30 22:09:27 volumio sudo[1424]: pam_unix(sudo:session): session closed for user root May 30 22:09:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. May 30 22:09:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 30 22:09:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 30 22:09:27 volumio go-librespot[1653]: go-librespot daemon starting... May 30 22:09:27 volumio go-librespot[1654]: time="2026-05-30T22:09:27-06:00" level=info msg="running go-librespot 0.7.1" May 30 22:09:27 volumio go-librespot[1654]: time="2026-05-30T22:09:27-06:00" level=debug msg="app state loaded" May 30 22:09:27 volumio go-librespot[1654]: time="2026-05-30T22:09:27-06:00" level=debug msg="stored credentials not found" May 30 22:09:27 volumio go-librespot[1654]: time="2026-05-30T22:09:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 30 22:09:28 volumio sudo[1664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-30 22:08' May 30 22:09:28 volumio sudo[1664]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"