Nov 03 10:09:00 volumio volumio[1128]: info: BOOT COMPLETED Nov 03 10:09:00 volumio sudo[2029]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 03 10:09:00 volumio sudo[2029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:00 volumio sudo[2029]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:00 volumio sudo[2031]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 03 10:09:00 volumio sudo[2031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:00 volumio sudo[2031]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:00 volumio sudo[2034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 03 10:09:00 volumio sudo[2034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:00 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Nov 03 10:09:00 volumio (upmpdcli)[2037]: upmpdcli.service: Failed to locate executable /usr/bin/upmpdcli: No such file or directory Nov 03 10:09:00 volumio (upmpdcli)[2037]: upmpdcli.service: Failed at step EXEC spawning /usr/bin/upmpdcli: No such file or directory Nov 03 10:09:00 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=203/EXEC Nov 03 10:09:00 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Nov 03 10:09:01 volumio sudo[2034]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:01 volumio volumio[1128]: info: Upmpdcli Daemon Started Nov 03 10:09:03 volumio ntpd[955]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Nov 03 10:09:03 volumio ntpd[955]: DNS: dns_check: DNS error: -11, System error Nov 03 10:09:03 volumio ntpd[955]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Nov 03 10:09:03 volumio ntpd[955]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Nov 03 10:09:06 volumio hostapd[1941]: wlan0: STA b6:06:92:4f:27:94 IEEE 802.11: associated Nov 03 10:09:06 volumio hostapd[1941]: wlan0: STA b6:06:92:4f:27:94 RADIUS: starting accounting session 7E5782DE6A6F03BB Nov 03 10:09:10 volumio dnsmasq-dhcp[1947]: DHCPDISCOVER(wlan0) b6:06:92:4f:27:94 Nov 03 10:09:10 volumio dnsmasq-dhcp[1947]: DHCPOFFER(wlan0) 192.168.211.144 b6:06:92:4f:27:94 Nov 03 10:09:10 volumio dnsmasq-dhcp[1947]: DHCPDISCOVER(wlan0) b6:06:92:4f:27:94 Nov 03 10:09:10 volumio dnsmasq-dhcp[1947]: DHCPOFFER(wlan0) 192.168.211.144 b6:06:92:4f:27:94 Nov 03 10:09:10 volumio dnsmasq-dhcp[1947]: DHCPDISCOVER(wlan0) b6:06:92:4f:27:94 Nov 03 10:09:10 volumio dnsmasq-dhcp[1947]: DHCPOFFER(wlan0) 192.168.211.144 b6:06:92:4f:27:94 Nov 03 10:09:10 volumio dnsmasq-dhcp[1947]: DHCPREQUEST(wlan0) 192.168.211.144 b6:06:92:4f:27:94 Nov 03 10:09:10 volumio dnsmasq-dhcp[1947]: DHCPACK(wlan0) 192.168.211.144 b6:06:92:4f:27:94 Nov 03 10:09:13 volumio volumio[1128]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.064&uuid=30a68afdda80d906539d2438fcb03de5" http://updates.volumio.org/downloader-v1/track-device Nov 03 10:09:13 volumio volumio[1128]: % Total % Received % Xferd Average Speed Time Time Time Current Nov 03 10:09:13 volumio volumio[1128]: Dload Upload Total Spent Left Speed Nov 03 10:09:13 volumio volumio[1128]: [843B blob data] Nov 03 10:09:13 volumio volumio[1128]: retrying in 5 seconds, trial 2 Nov 03 10:09:13 volumio volumio[1128]: info: Volumio Calling Home Nov 03 10:09:15 volumio sudo[2061]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 03 10:09:15 volumio sudo[2061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:15 volumio sudo[2061]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:15 volumio sudo[2063]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 03 10:09:15 volumio sudo[2063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:15 volumio sudo[2063]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:15 volumio volumio[1128]: verbose: New Socket.io Connection to 192.168.211.1 from 192.168.211.144 UA: Mozilla/5.0 (Linux; Android 16; Pixel 8 Pro Build/BP3A.251005.004.B2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.49 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::volumioGetVisibleSources Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Nov 03 10:09:15 volumio volumio[1128]: info: Received Get System Info Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 03 10:09:15 volumio volumio[1128]: info: Discovery: Getting this device information Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:09:15 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 03 10:09:15 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:15.788Z level=DEBUG msg="received event" component=volumio/socket event=ClientUpdateCheck Nov 03 10:09:15 volumio volumio-remote-updater[735]: Test mode disabled Nov 03 10:09:15 volumio volumio-remote-updater[735]: Alpha mode disabled Nov 03 10:09:15 volumio volumio-remote-updater[735]: Alpha legacy test mode disabled Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 03 10:09:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 03 10:09:16 volumio ntpd[955]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Nov 03 10:09:16 volumio ntpd[955]: DNS: dns_check: DNS error: -11, System error Nov 03 10:09:16 volumio ntpd[955]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Nov 03 10:09:16 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 03 10:09:16 volumio ntpd[955]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Nov 03 10:09:17 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Nov 03 10:09:17 volumio volumio[1128]: info: Loading i18n strings for locale de Nov 03 10:09:17 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Nov 03 10:09:17 volumio volumio[1128]: info: Setting timezone to Europe/Berlin Nov 03 10:09:17 volumio sudo[2074]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Nov 03 10:09:17 volumio sudo[2074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:17 volumio sudo[2074]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:17 volumio sudo[2078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Europe/Berlin /etc/localtime Nov 03 10:09:17 volumio sudo[2078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:17 volumio sudo[2078]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:17 volumio sudo[2082]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Nov 03 10:09:17 volumio sudo[2082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:17 volumio sudo[2082]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:18 volumio sudo[2086]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Europe/Berlin Nov 03 10:09:18 volumio sudo[2086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:18 volumio dbus-daemon[714]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.21' (uid=0 pid=2087 comm="/usr/bin/timedatectl set-timezone Europe/Berlin") Nov 03 10:09:18 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Nov 03 10:09:18 volumio dbus-daemon[714]: [system] Successfully activated service 'org.freedesktop.timedate1' Nov 03 10:09:18 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Nov 03 10:09:18 volumio sudo[2086]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:18 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Nov 03 10:09:18 volumio volumio[1128]: info: Loading i18n strings for locale de Nov 03 10:09:18 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Nov 03 10:09:18 volumio volumio[1128]: info: Setting timezone to Europe/Berlin Nov 03 10:09:19 volumio sudo[2105]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Nov 03 10:09:19 volumio sudo[2105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:19 volumio sudo[2105]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:19 volumio sudo[2109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Europe/Berlin /etc/localtime Nov 03 10:09:19 volumio sudo[2109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:19 volumio sudo[2109]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:19 volumio sudo[2113]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Nov 03 10:09:19 volumio sudo[2113]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:19 volumio sudo[2113]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:19 volumio sudo[2117]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Europe/Berlin Nov 03 10:09:19 volumio sudo[2117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:19 volumio sudo[2117]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:19 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Nov 03 10:09:19 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Nov 03 10:09:20 volumio sudo[2120]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 03 10:09:20 volumio sudo[2120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:20 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:20.110Z level=DEBUG msg="received event" component=volumio/socket event=pushMenuItems Nov 03 10:09:20 volumio volumio[1128]: Updating browse sources language Nov 03 10:09:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 03 10:09:20 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:20.169Z level=DEBUG msg="received event" component=volumio/socket event=pushBrowseSources Nov 03 10:09:20 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:20.277Z level=DEBUG msg="received event" component=volumio/socket event=pushMenuItems Nov 03 10:09:20 volumio volumio[1128]: Updating browse sources language Nov 03 10:09:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 03 10:09:20 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:20.338Z level=DEBUG msg="received event" component=volumio/socket event=pushBrowseSources Nov 03 10:09:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAudioDevices Nov 03 10:09:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 03 10:09:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:20 volumio sudo[2120]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:21 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:21.372Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4=169.254.246.173/16 ip6= Nov 03 10:09:21 volumio volumio[1128]: info: Received Get System Info Nov 03 10:09:21 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 03 10:09:21 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 03 10:09:21 volumio volumio[1128]: info: Discovery: Getting this device information Nov 03 10:09:21 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:09:21 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:21 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 03 10:09:21 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:21.381Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 03 10:09:21 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 03 10:09:21 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 03 10:09:21 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:21.423Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 03 10:09:21 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:21.424Z level=INFO msg="BLE descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:09:21 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:21.426Z level=INFO msg="mDNS descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:09:22 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Nov 03 10:09:22 volumio volumio[1128]: info: Preparing to save Alsa Options, stopping services first Nov 03 10:09:22 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:09:22 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:22 volumio volumio[1128]: info: CoreCommandRouter::volumioPause Nov 03 10:09:22 volumio volumio[1128]: info: CoreStateMachine::pause Nov 03 10:09:22 volumio volumio[1128]: info: Saving Audio Output to: {"i2s":false,"output_device":{"value":"0","label":"HDMI Out"},"disallowPush":true} Nov 03 10:09:22 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:22 volumio volumio[1128]: info: Enabling PI HDMI Output Nov 03 10:09:22 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:22 volumio volumio[1128]: info: Found match in Cards Database: setting mixer PCM for card HDMI Out Nov 03 10:09:22 volumio volumio[1128]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 03 10:09:22 volumio volumio[1128]: info: Updating Volume Controller Parameters: Device: 0 Name: HDMI Out Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 03 10:09:22 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 03 10:09:22 volumio volumio[1128]: info: Disabling external Volume Control Nov 03 10:09:22 volumio volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 03 10:09:23 volumio volumio[1128]: info: Preparing to generate the ALSA configuration file Nov 03 10:09:23 volumio volumio[1128]: info: Raspberry PI HDMI Output Enabled Nov 03 10:09:23 volumio sudo[2140]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl store Nov 03 10:09:23 volumio sudo[2140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:23 volumio sudo[2140]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:23 volumio volumio[1128]: info: Asound.conf file unchanged, so no further update is needed Nov 03 10:09:23 volumio volumio[1128]: info: Output device has changed, restarting MPD Nov 03 10:09:23 volumio sudo[2145]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 03 10:09:23 volumio sudo[2145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:23 volumio volumio[1128]: info: Output device has changed, restarting Shairport Sync Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:23 volumio sudo[2145]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:23 volumio sudo[2150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 03 10:09:23 volumio volumio-remote-updater[735]: curl_easy_perform() failed: Couldn't resolve host name Nov 03 10:09:23 volumio volumio-remote-updater[735]: terminate called after throwing an instance of 'std::invalid_argument' Nov 03 10:09:23 volumio volumio-remote-updater[735]: what(): parse error - unexpected end of input Nov 03 10:09:23 volumio systemd[1]: volumio-remote-updater.service: Main process exited, code=killed, status=6/ABRT Nov 03 10:09:23 volumio systemd[1]: volumio-remote-updater.service: Failed with result 'signal'. Nov 03 10:09:23 volumio sudo[2150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:23 volumio volumio[1128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 03 10:09:23 volumio systemd[1]: volumio-remote-updater.service: Scheduled restart job, restart counter is at 1. Nov 03 10:09:23 volumio systemd[1]: Stopped volumio-remote-updater.service - Volumio Remote OTA Updater. Nov 03 10:09:23 volumio systemd[1]: Started volumio-remote-updater.service - Volumio Remote OTA Updater. Nov 03 10:09:23 volumio volumio-remote-updater[2155]: Volumio OTA Client: 1.7.0 Nov 03 10:09:23 volumio volumio-remote-updater[2155]: Error: No active session Nov 03 10:09:23 volumio volumio-remote-updater[2155]: [2025-11-03 10:09:23] [connect] Successful connection Nov 03 10:09:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 03 10:09:23 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 03 10:09:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 03 10:09:23 volumio systemd[1]: mpd.service: Consumed 5.549s CPU time. Nov 03 10:09:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 03 10:09:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 03 10:09:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 03 10:09:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Nov 03 10:09:24 volumio volumio[1128]: info: MPD Permissions set Nov 03 10:09:24 volumio volumio[1128]: info: VolumeController:: Volume=86 Mute =false Nov 03 10:09:24 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:24 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:24.087Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 03 10:09:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 03 10:09:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:24.145Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:24 volumio volumio[1128]: info: Alsa Settings successfully stored Nov 03 10:09:24 volumio volumio-remote-updater[2155]: [2025-11-03 10:09:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1762160963 101 Nov 03 10:09:24 volumio volumio[1128]: 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: 4 Nov 03 10:09:24 volumio sudo[2167]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 03 10:09:24 volumio sudo[2167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 03 10:09:24 volumio sudo[2167]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:24 volumio volumio[1128]: info: Starting Shairport Sync Nov 03 10:09:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAudioDevices Nov 03 10:09:24 volumio sudo[2176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 03 10:09:24 volumio sudo[2176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 03 10:09:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 03 10:09:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 03 10:09:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:09:25 volumio systemd[1]: shairport-sync.service: Consumed 1.476s CPU time. Nov 03 10:09:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:09:25 volumio sudo[2176]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:25 volumio volumio[1128]: info: Shairport-Sync Started Nov 03 10:09:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Nov 03 10:09:26 volumio volumio[1128]: info: Preparing to save Alsa Options, stopping services first Nov 03 10:09:26 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:09:26 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:26 volumio volumio[1128]: info: CoreCommandRouter::volumioPause Nov 03 10:09:26 volumio volumio[1128]: info: CoreStateMachine::pause Nov 03 10:09:26 volumio volumio[1128]: info: Saving Audio Output to: {"i2s":false,"output_device":{"value":"0","label":"HDMI Out"},"disallowPush":true} Nov 03 10:09:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:26 volumio volumio[1128]: info: Enabling PI HDMI Output Nov 03 10:09:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:26 volumio volumio[1128]: info: Found match in Cards Database: setting mixer PCM for card HDMI Out Nov 03 10:09:26 volumio volumio[1128]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 03 10:09:26 volumio volumio[1128]: info: Updating Volume Controller Parameters: Device: 0 Name: HDMI Out Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 03 10:09:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 03 10:09:26 volumio volumio[1128]: info: Disabling external Volume Control Nov 03 10:09:26 volumio volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 03 10:09:27 volumio volumio[1128]: info: Preparing to generate the ALSA configuration file Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Nov 03 10:09:27 volumio volumio[1128]: info: CoreStateMachine::getcurrentVolume Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrievevolume Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Nov 03 10:09:27 volumio volumio[1128]: info: Raspberry PI HDMI Output Enabled Nov 03 10:09:27 volumio volumio[1128]: info: VolumeController:: Volume=86 Mute =false Nov 03 10:09:27 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:27 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:27 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:27.297Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:27 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:27.309Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:27 volumio sudo[2211]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl store Nov 03 10:09:27 volumio sudo[2211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAudioDevices Nov 03 10:09:27 volumio mpd[2169]: 2025-11-03T10:09:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 03 10:09:27 volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 03 10:09:27 volumio sudo[2150]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:27 volumio sudo[2211]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 03 10:09:28 volumio volumio[1128]: info: Asound.conf file unchanged, so no further update is needed Nov 03 10:09:28 volumio volumio[1128]: info: Output device has changed, restarting MPD Nov 03 10:09:28 volumio volumio[1128]: info: Output device has changed, restarting Shairport Sync Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:28 volumio sudo[2229]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 03 10:09:28 volumio sudo[2229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:28 volumio sudo[2231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 03 10:09:28 volumio sudo[2229]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:28 volumio sudo[2231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:28 volumio volumio[1128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 03 10:09:28 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 03 10:09:28 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 03 10:09:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 03 10:09:28 volumio systemd[1]: mpd.service: Consumed 3.078s CPU time. Nov 03 10:09:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 03 10:09:28 volumio volumio[1128]: info: VolumeController:: Volume=86 Mute =false Nov 03 10:09:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 03 10:09:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 03 10:09:28 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:28 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:28 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:28.702Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 03 10:09:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 03 10:09:28 volumio volumio[1128]: info: CoreStateMachine::updateTrackBlock Nov 03 10:09:28 volumio volumio[1128]: info: CorePlayQueue::getTrackBlock Nov 03 10:09:28 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrievevolume Nov 03 10:09:28 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:28.857Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:28 volumio volumio[1128]: info: Alsa Settings successfully stored Nov 03 10:09:28 volumio sudo[2252]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 03 10:09:28 volumio sudo[2252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 03 10:09:28 volumio sudo[2252]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:28 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:28.963Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 03 10:09:29 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Nov 03 10:09:29 volumio volumio[1128]: info: Preparing to save Alsa Options, stopping services first Nov 03 10:09:29 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:09:29 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:29 volumio volumio[1128]: info: CoreCommandRouter::volumioPause Nov 03 10:09:29 volumio volumio[1128]: info: CoreStateMachine::pause Nov 03 10:09:29 volumio volumio[1128]: info: Saving Audio Output to: {"i2s":false,"output_device":{"value":"0","label":"HDMI Out"},"disallowPush":true} Nov 03 10:09:29 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:29 volumio volumio[1128]: info: Enabling PI HDMI Output Nov 03 10:09:29 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:29 volumio volumio[1128]: info: Found match in Cards Database: setting mixer PCM for card HDMI Out Nov 03 10:09:29 volumio ntpd[955]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Nov 03 10:09:29 volumio ntpd[955]: DNS: dns_check: DNS error: -11, System error Nov 03 10:09:29 volumio ntpd[955]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Nov 03 10:09:29 volumio volumio[1128]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 03 10:09:29 volumio volumio[1128]: info: Updating Volume Controller Parameters: Device: 0 Name: HDMI Out Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 03 10:09:29 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 03 10:09:29 volumio volumio[1128]: info: Disabling external Volume Control Nov 03 10:09:29 volumio volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 03 10:09:29 volumio volumio[1128]: info: Preparing to generate the ALSA configuration file Nov 03 10:09:29 volumio volumio[1128]: info: MPD Permissions set Nov 03 10:09:29 volumio ntpd[955]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Nov 03 10:09:30 volumio volumio[1128]: info: Raspberry PI HDMI Output Enabled Nov 03 10:09:30 volumio volumio[1128]: info: VolumeController:: Volume=86 Mute =false Nov 03 10:09:30 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:30 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:30 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:30.356Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:30 volumio sudo[2273]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl store Nov 03 10:09:30 volumio sudo[2273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:30 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:30.431Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:30 volumio sudo[2273]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:30 volumio volumio[1128]: info: Alsa Settings successfully stored Nov 03 10:09:30 volumio volumio[1128]: info: VolumeController:: Volume=86 Mute =false Nov 03 10:09:30 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:30 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:30 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:30 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:30.720Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:30 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:30.790Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 03 10:09:31 volumio volumio[1128]: info: Asound.conf file unchanged, so no further update is needed Nov 03 10:09:31 volumio volumio[1128]: info: Output device has changed, restarting MPD Nov 03 10:09:31 volumio volumio[1128]: info: Output device has changed, restarting Shairport Sync Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:31 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:31 volumio sudo[2291]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 03 10:09:31 volumio sudo[2293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 03 10:09:31 volumio sudo[2291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:31 volumio sudo[2291]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:31 volumio sudo[2293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:32 volumio volumio[1128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Nov 03 10:09:32 volumio volumio[1128]: info: CoreStateMachine::getcurrentVolume Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrievevolume Nov 03 10:09:32 volumio mpd[2256]: 2025-11-03T10:09:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 03 10:09:32 volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 03 10:09:32 volumio sudo[2231]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Nov 03 10:09:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 03 10:09:32 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 03 10:09:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 03 10:09:32 volumio systemd[1]: mpd.service: Consumed 3.039s CPU time. Nov 03 10:09:32 volumio volumio[1128]: info: MPD Permissions set Nov 03 10:09:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 03 10:09:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 03 10:09:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 03 10:09:32 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:32.278Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 03 10:09:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 03 10:09:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 03 10:09:32 volumio sudo[2304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 03 10:09:32 volumio sudo[2304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:32 volumio volumio[1128]: info: Starting Shairport Sync Nov 03 10:09:32 volumio volumio[1128]: error: updateQueue error: null Nov 03 10:09:32 volumio volumio[1128]: error: MPD error: Error: connect ECONNRESET /run/mpd/socket Nov 03 10:09:32 volumio volumio[1128]: info: VolumeController:: Volume=86 Mute =false Nov 03 10:09:32 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:32 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:32 volumio sudo[2307]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 03 10:09:32 volumio sudo[2307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 03 10:09:32 volumio sudo[2307]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:32 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:32.554Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:32 volumio volumio[1128]: info: CoreStateMachine::updateTrackBlock Nov 03 10:09:32 volumio volumio[1128]: info: CorePlayQueue::getTrackBlock Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrievevolume Nov 03 10:09:32 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:32.610Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:32 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 03 10:09:32 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 03 10:09:32 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 03 10:09:32 volumio sudo[2310]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 03 10:09:32 volumio sudo[2310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 03 10:09:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 03 10:09:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:09:32 volumio systemd[1]: shairport-sync.service: Consumed 1.270s CPU time. Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:32 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:09:32 volumio sudo[2310]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:33 volumio volumio[1128]: info: Shairport-Sync Started Nov 03 10:09:33 volumio volumio[1128]: info: Starting Shairport Sync Nov 03 10:09:33 volumio volumio[1128]: info: VolumeController:: Volume=86 Mute =false Nov 03 10:09:33 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:33 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:33 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:33 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:33.407Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:33 volumio sudo[2337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 03 10:09:33 volumio sudo[2337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:33 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:33.506Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:33 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Nov 03 10:09:33 volumio volumio[1128]: info: CoreStateMachine::getcurrentVolume Nov 03 10:09:33 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrievevolume Nov 03 10:09:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 03 10:09:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 03 10:09:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:09:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:09:33 volumio sudo[2337]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:33 volumio volumio[1128]: info: Shairport-Sync Started Nov 03 10:09:34 volumio volumio[1128]: info: VolumeController:: Volume=86 Mute =false Nov 03 10:09:34 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:34 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:34 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:34 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:34.027Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:34 volumio volumio[1128]: info: CoreStateMachine::updateTrackBlock Nov 03 10:09:34 volumio volumio[1128]: info: CorePlayQueue::getTrackBlock Nov 03 10:09:34 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrievevolume Nov 03 10:09:34 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:34.160Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:34 volumio volumio[1128]: info: VolumeController:: Volume=86 Mute =false Nov 03 10:09:34 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:34 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:34 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:34 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:34.423Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:34 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:34.429Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:35 volumio sudo[2359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 03 10:09:35 volumio sudo[2359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:35 volumio mpd[2312]: 2025-11-03T10:09:35 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 03 10:09:35 volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 03 10:09:35 volumio sudo[2293]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:35 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:35.796Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 03 10:09:35 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 03 10:09:35 volumio mpd_monitor.sh[2363]: MPD Monitor Service: Starting MPD Monitor Service Nov 03 10:09:35 volumio sudo[2359]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:35 volumio sudo[2304]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:35 volumio volumio[1128]: error: updateQueue error: null Nov 03 10:09:35 volumio volumio[1128]: info: Successfully started MPD Monitor Nov 03 10:09:35 volumio volumio[1128]: info: Successfully started MPD Monitor Nov 03 10:09:37 volumio volumio[1128]: error: updateQueue error: null Nov 03 10:09:38 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAudioDevices Nov 03 10:09:38 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 03 10:09:38 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:38 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:39 volumio sudo[2379]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 03 10:09:39 volumio sudo[2379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:39 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 03 10:09:39 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 03 10:09:39 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 03 10:09:39 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 03 10:09:39 volumio mpd_monitor.sh[2387]: MPD Monitor Service: Starting MPD Monitor Service Nov 03 10:09:39 volumio sudo[2379]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:39 volumio volumio[1128]: info: Successfully started MPD Monitor Nov 03 10:09:41 volumio ntpd[955]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Nov 03 10:09:41 volumio ntpd[955]: DNS: dns_check: DNS error: -11, System error Nov 03 10:09:41 volumio ntpd[955]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Nov 03 10:09:46 volumio volumio[1128]: info: Preparing to save Alsa Options, stopping services first Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:09:46 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::volumioPause Nov 03 10:09:46 volumio volumio[1128]: info: CoreStateMachine::pause Nov 03 10:09:46 volumio volumio[1128]: info: Saving Audio Output to: {"i2s":true,"i2sid":{"value":"hifiberry-dacpluspro","label":"HiFiBerry DAC+ Pro"},"output_device":{"value":1,"label":"HiFiBerry DAC+ Pro"},"disallowPush":true} Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:46 volumio volumio[1128]: info: Enabling I2S DAC: HiFiBerry DAC+ Pro Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , enableI2SDAC Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:46 volumio sudo[2393]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Nov 03 10:09:46 volumio sudo[2393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:46 volumio sudo[2393]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:46 volumio volumio[1128]: info: No Overlays Loaded Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName Nov 03 10:09:46 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:47 volumio sudo[2396]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay hifiberry-dacplus Nov 03 10:09:47 volumio sudo[2396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:47 volumio volumio[1128]: warn: Unable to locate the device HiFiBerry DAC+ Pro a reboot may be required. Nov 03 10:09:47 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2s@7e203000/status Nov 03 10:09:47 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2c@7e804000/status Nov 03 10:09:47 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/compatible Nov 03 10:09:47 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/i2s-controller Nov 03 10:09:47 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/status Nov 03 10:09:47 volumio sudo[2396]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:47 volumio volumio[1128]: info: Found match in i2s Card Database: setting mixer Digital for card HiFiBerry DAC+ Pro Nov 03 10:09:47 volumio (udev-worker)[2407]: controlC2: Process '/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore 2' failed with exit code 99. Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 03 10:09:47 volumio volumio[1128]: info: Updating Volume Controller Parameters: Device: 2 Name: HiFiBerry DAC+ Pro Mixer: Digital Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 03 10:09:47 volumio volumio[1128]: info: Disabling external Volume Control Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Nov 03 10:09:47 volumio volumio[1128]: info: Preparing to generate the ALSA configuration file Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Nov 03 10:09:47 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Nov 03 10:09:47 volumio sudo[2434]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 03 10:09:47 volumio volumio[1128]: info: I2S Param [object Object] successfully enabled Nov 03 10:09:47 volumio sudo[2434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:47 volumio sudo[2436]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 03 10:09:47 volumio sudo[2436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:47 volumio sudo[2436]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 03 10:09:48 volumio volumio[1128]: info: Getting Alsa Cards List without I2S DAC Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 03 10:09:48 volumio volumio[1128]: info: VolumeController:: Volume=100 Mute =false Nov 03 10:09:48 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:48 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 03 10:09:48 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:48 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:48.764Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:48 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:48.784Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:48 volumio sudo[2434]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:48 volumio volumio[1128]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Nov 03 10:09:48 volumio volumio[1128]: wlan0 Interface doesn't support scanning : Device or resource busy Nov 03 10:09:48 volumio volumio[1128]: info: Cannot use regular scanning, forcing with ap-force Nov 03 10:09:48 volumio sudo[2459]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Nov 03 10:09:48 volumio sudo[2459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:49 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:49.252Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4=169.254.246.173/16 ip6= Nov 03 10:09:49 volumio sudo[2459]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:49 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Nov 03 10:09:49 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Nov 03 10:09:49 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 03 10:09:49 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Nov 03 10:09:49 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 03 10:09:50 volumio volumio[1128]: info: Received Get System Info Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 03 10:09:50 volumio volumio[1128]: info: Discovery: Getting this device information Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:09:50 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 03 10:09:50 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:50.128Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 03 10:09:50 volumio volumio[1128]: info: Asound.conf file written Nov 03 10:09:50 volumio sudo[2480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Nov 03 10:09:50 volumio sudo[2480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:50 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:50.355Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4=169.254.246.173/16 ip6= Nov 03 10:09:50 volumio sudo[2480]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:50 volumio volumio[1128]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Nov 03 10:09:50 volumio volumio[1128]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Nov 03 10:09:50 volumio volumio[1128]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Nov 03 10:09:50 volumio volumio[1128]: No state is present for card sndrpihifiberry Nov 03 10:09:50 volumio volumio[1128]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Nov 03 10:09:50 volumio volumio[1128]: Found hardware: "HifiberryDacp" "" "" "" "" Nov 03 10:09:50 volumio volumio[1128]: Hardware is initialized using a generic method Nov 03 10:09:50 volumio volumio[1128]: No state is present for card sndrpihifiberry Nov 03 10:09:50 volumio volumio[1128]: info: Output device has changed, restarting MPD Nov 03 10:09:50 volumio volumio[1128]: info: Output device has changed, restarting Shairport Sync Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:50 volumio sudo[2488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 03 10:09:50 volumio sudo[2488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:50 volumio sudo[2486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 03 10:09:50 volumio sudo[2486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:50 volumio sudo[2486]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:50 volumio volumio[1128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 03 10:09:50 volumio volumio[1128]: info: Output device has changed, restarting MPD Nov 03 10:09:50 volumio volumio[1128]: info: Output device has changed, restarting Shairport Sync Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:50 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 03 10:09:50 volumio volumio[1128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 03 10:09:50 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 03 10:09:50 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 03 10:09:50 volumio systemd[1]: mpd.service: Consumed 3.110s CPU time. Nov 03 10:09:50 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 03 10:09:50 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 03 10:09:50 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 03 10:09:50 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:50.894Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 03 10:09:50 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:50.896Z level=INFO msg="BLE descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:09:50 volumio volumio[1128]: info: Received Get System Info Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 03 10:09:50 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:50.900Z level=INFO msg="mDNS descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 03 10:09:50 volumio volumio[1128]: info: Discovery: Getting this device information Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:09:50 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 03 10:09:50 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:50.904Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 03 10:09:50 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 03 10:09:50 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:50.917Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 03 10:09:50 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:50.919Z level=INFO msg="BLE descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:09:50 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:50.921Z level=INFO msg="mDNS descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:09:50 volumio volumio[1128]: info: MPD Permissions set Nov 03 10:09:50 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 03 10:09:50 volumio sudo[2497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 03 10:09:50 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 03 10:09:50 volumio sudo[2497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 03 10:09:51 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 03 10:09:51 volumio sudo[2501]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 03 10:09:51 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 03 10:09:51 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 03 10:09:51 volumio sudo[2501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:51 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 03 10:09:51 volumio sudo[2501]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:51 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:09:51 volumio volumio[1128]: info: MPD Permissions set Nov 03 10:09:51 volumio volumio[1128]: info: Starting Shairport Sync Nov 03 10:09:51 volumio sudo[2510]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 03 10:09:51 volumio sudo[2510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 03 10:09:51 volumio sudo[2510]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:51 volumio volumio[1128]: info: Starting Shairport Sync Nov 03 10:09:51 volumio sudo[2522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 03 10:09:51 volumio sudo[2522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:51 volumio sudo[2525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 03 10:09:51 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 03 10:09:51 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 03 10:09:51 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:09:51 volumio systemd[1]: shairport-sync.service: Consumed 1.481s CPU time. Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Nov 03 10:09:51 volumio volumio[1128]: info: CoreStateMachine::getcurrentVolume Nov 03 10:09:51 volumio sudo[2525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrievevolume Nov 03 10:09:51 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:09:51 volumio sudo[2522]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:51 volumio volumio[1128]: info: Shairport-Sync Started Nov 03 10:09:51 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 03 10:09:51 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 03 10:09:51 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:09:51 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:09:51 volumio sudo[2525]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:51 volumio volumio[1128]: info: Shairport-Sync Started Nov 03 10:09:51 volumio volumio[1128]: info: VolumeController:: Volume=100 Mute =false Nov 03 10:09:51 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:51 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:51 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:51 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:51.964Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:52 volumio volumio[1128]: info: CoreStateMachine::updateTrackBlock Nov 03 10:09:52 volumio volumio[1128]: info: CorePlayQueue::getTrackBlock Nov 03 10:09:52 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrievevolume Nov 03 10:09:52 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:52.079Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:52 volumio volumio[1128]: info: VolumeController:: Volume=100 Mute =false Nov 03 10:09:52 volumio volumio[1128]: info: CoreStateMachine::pushState Nov 03 10:09:52 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:09:52 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Nov 03 10:09:52 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:52.511Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:09:52 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:52.545Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 03 10:09:54 volumio mpd[2521]: 2025-11-03T10:09:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 03 10:09:54 volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 03 10:09:54 volumio sudo[2488]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:54 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:54.500Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 03 10:09:54 volumio sudo[2497]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:54 volumio volumio5-onboarding[1678]: time=2025-11-03T09:09:54.590Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 03 10:09:54 volumio volumio[1128]: error: MPD error: The expression evaluated to a falsy value: Nov 03 10:09:54 volumio volumio[1128]: assert.ok(self.idling) Nov 03 10:09:54 volumio volumio[1128]: error: The expression evaluated to a falsy value: Nov 03 10:09:54 volumio volumio[1128]: assert.ok(self.idling) Nov 03 10:09:54 volumio volumio[1128]: error: updateQueue error: null Nov 03 10:09:57 volumio sudo[2550]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 03 10:09:57 volumio sudo[2550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:57 volumio sudo[2552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 03 10:09:57 volumio sudo[2552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:09:57 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 03 10:09:57 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 03 10:09:57 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 03 10:09:57 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 03 10:09:57 volumio mpd_monitor.sh[2555]: MPD Monitor Service: Starting MPD Monitor Service Nov 03 10:09:58 volumio sudo[2550]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:58 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 03 10:09:58 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 03 10:09:58 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 03 10:09:58 volumio volumio[1128]: info: Successfully started MPD Monitor Nov 03 10:09:58 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 03 10:09:58 volumio mpd_monitor.sh[2558]: MPD Monitor Service: Starting MPD Monitor Service Nov 03 10:09:58 volumio sudo[2552]: pam_unix(sudo:session): session closed for user root Nov 03 10:09:58 volumio volumio[1128]: info: Successfully started MPD Monitor Nov 03 10:10:09 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , connectWirelessNetwork Nov 03 10:10:09 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getWiredInfo Nov 03 10:10:09 volumio sudo[2591]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 03 10:10:09 volumio sudo[2591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:09 volumio sudo[2591]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:12 volumio volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 03 10:10:14 volumio volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 03 10:10:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getDonation Nov 03 10:10:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware Nov 03 10:10:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getDonationsArray Nov 03 10:10:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getDoneMessage Nov 03 10:10:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware Nov 03 10:10:16 volumio volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 03 10:10:18 volumio volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 03 10:10:18 volumio volumio[1128]: info: CALLMETHOD: system_controller system saveUpdateSettings [object Object] Nov 03 10:10:18 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , saveUpdateSettings Nov 03 10:10:18 volumio volumio[1128]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'value') Nov 03 10:10:19 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Nov 03 10:10:19 volumio volumio[1128]: info: CoreCommandRouter::Reload Ui Nov 03 10:10:19 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:19.576Z level=DEBUG msg="received event" component=volumio/socket event=reloadUi Nov 03 10:10:19 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , setShowWizard Nov 03 10:10:19 volumio volumio[1128]: info: Wizard terminated Successfully Nov 03 10:10:19 volumio volumio[1128]: info: CoreCommandRouter::volumiosetStartupVolume Nov 03 10:10:19 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 03 10:10:19 volumio volumio[1128]: info: Player Reboot required after I2S DAC has been enabled in wizard Nov 03 10:10:19 volumio volumio[1128]: info: Executing Deferred Wifi Connection Nov 03 10:10:19 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings Nov 03 10:10:19 volumio volumio[1128]: info: Saving new wireless network Nov 03 10:10:19 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:19.962Z level=DEBUG msg="received event" component=volumio/socket event=closeWizard Nov 03 10:10:19 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:19.971Z level=DEBUG msg="received event" component=volumio/socket event=openModal Nov 03 10:10:19 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:19.986Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 03 10:10:20 volumio volumio[1128]: info: Received Get System Info Nov 03 10:10:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 03 10:10:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 03 10:10:20 volumio volumio[1128]: info: Discovery: Getting this device information Nov 03 10:10:20 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:10:20 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:10:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 03 10:10:20 volumio sudo[2611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf Nov 03 10:10:20 volumio sudo[2611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:20 volumio sudo[2611]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:20 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:20.197Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 03 10:10:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 03 10:10:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 03 10:10:20 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:20.239Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 03 10:10:20 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:20.241Z level=INFO msg="BLE descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:10:20 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:20.243Z level=INFO msg="mDNS descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:10:20 volumio volumio[1128]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 03 10:10:20 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Nov 03 10:10:20 volumio volumio[1128]: info: Discovery: Restarting Advertising due to device name change Nov 03 10:10:20 volumio sudo[2614]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Nov 03 10:10:20 volumio sudo[2614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:20 volumio systemd[1]: Stopping wireless.service - Wireless Services... Nov 03 10:10:20 volumio systemd[1]: wireless.service: Deactivated successfully. Nov 03 10:10:20 volumio systemd[1]: Stopped wireless.service - Wireless Services. Nov 03 10:10:20 volumio systemd[1]: wireless.service: Consumed 3min 15.009s CPU time. Nov 03 10:10:20 volumio systemd[1]: Starting wireless.service - Wireless Services... Nov 03 10:10:21 volumio sudo[2633]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 03 10:10:21 volumio sudo[2633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:21 volumio volumio[1128]: info: Discovery: A device disappeared from network Nov 03 10:10:21 volumio volumio[1128]: info: Discovery: Device volumio disappeared from network Nov 03 10:10:21 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:21.495Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:10:21 volumio sudo[2633]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:21 volumio volumio[1128]: info: Discovery: A device disappeared from network Nov 03 10:10:21 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:21.534Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 03 10:10:21 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:21.615Z level=DEBUG msg="received event" component=volumio/socket event=pushSaveWirelessNetworkSettings Nov 03 10:10:22 volumio wireless.js[2617]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Nov 03 10:10:22 volumio wireless.js[2617]: WIRELESS.JS: Wireless.js initializing wireless flow Nov 03 10:10:22 volumio wireless.js[2617]: WIRELESS.JS: Cleaning previous... Nov 03 10:10:22 volumio systemd[1]: Stopping dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... Nov 03 10:10:22 volumio dnsmasq[1947]: exiting on receipt of SIGTERM Nov 03 10:10:22 volumio systemd[1]: dnsmasq.service: Deactivated successfully. Nov 03 10:10:22 volumio systemd[1]: Stopped dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. Nov 03 10:10:22 volumio systemd[1]: Stopping hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... Nov 03 10:10:22 volumio sudo[2644]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 03 10:10:22 volumio sudo[2644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:22 volumio sudo[2644]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:22 volumio dhcpcd[832]: wlan0: carrier lost Nov 03 10:10:22 volumio systemd[1]: hostapd.service: Deactivated successfully. Nov 03 10:10:22 volumio systemd[1]: Stopped hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. Nov 03 10:10:23 volumio avahi-daemon[712]: Withdrawing address record for 169.254.246.173 on wlan0. Nov 03 10:10:23 volumio dhcpcd[832]: wlan0: deleting route to 169.254.0.0/16 Nov 03 10:10:23 volumio dhcpcd[832]: wlan0: deleting default route Nov 03 10:10:23 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Nov 03 10:10:23 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Nov 03 10:10:23 volumio systemd[1]: welcome.service: Deactivated successfully. Nov 03 10:10:23 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Nov 03 10:10:23 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Nov 03 10:10:23 volumio sudo[2660]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Nov 03 10:10:23 volumio sudo[2660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 03 10:10:23 volumio avahi-daemon[712]: Withdrawing address record for 192.168.211.1 on wlan0. Nov 03 10:10:23 volumio avahi-daemon[712]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Nov 03 10:10:23 volumio avahi-daemon[712]: Interface wlan0.IPv4 no longer relevant for mDNS. Nov 03 10:10:23 volumio sudo[2660]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:23 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Nov 03 10:10:23 volumio welcome[2668]: Resolved ip:[0] Nov 03 10:10:23 volumio sudo[2673]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Nov 03 10:10:23 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Nov 03 10:10:23 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Nov 03 10:10:23 volumio sudo[2673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 03 10:10:23 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Nov 03 10:10:23 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Nov 03 10:10:23 volumio systemd[1]: welcome.service: Deactivated successfully. Nov 03 10:10:23 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Nov 03 10:10:23 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Nov 03 10:10:23 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Nov 03 10:10:23 volumio sudo[2673]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:23 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:23.756Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4= ip6= Nov 03 10:10:23 volumio welcome[2680]: Resolved ip:[0] Nov 03 10:10:23 volumio volumio[1128]: info: Received Get System Info Nov 03 10:10:23 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Nov 03 10:10:23 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Nov 03 10:10:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 03 10:10:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 03 10:10:23 volumio volumio[1128]: info: Discovery: Getting this device information Nov 03 10:10:23 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:10:23 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:10:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 03 10:10:23 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:23.824Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 03 10:10:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 03 10:10:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 03 10:10:23 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:23.843Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 03 10:10:23 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:23.852Z level=INFO msg="BLE descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:10:23 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:23.854Z level=INFO msg="mDNS descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:10:23 volumio sudo[2683]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 03 10:10:23 volumio sudo[2683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:23 volumio sudo[2683]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:24 volumio wireless.js[2617]: WIRELESS.JS: Stopped aP Nov 03 10:10:24 volumio sudo[2694]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 03 10:10:24 volumio sudo[2694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:24.259Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4= ip6= Nov 03 10:10:24 volumio volumio[1128]: info: Received Get System Info Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 03 10:10:24 volumio volumio[1128]: info: Discovery: Getting this device information Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:10:24 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 03 10:10:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:24.284Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 03 10:10:24 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 03 10:10:24 volumio sudo[2694]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:24.328Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 03 10:10:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:24.330Z level=INFO msg="BLE descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:10:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:24.332Z level=INFO msg="mDNS descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:10:24 volumio sudo[2696]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Nov 03 10:10:24 volumio sudo[2696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:24 volumio sudo[2696]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:24 volumio sudo[2705]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 03 10:10:24 volumio sudo[2705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:24 volumio sudo[2705]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:24 volumio sudo[2706]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 03 10:10:24 volumio sudo[2708]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Nov 03 10:10:24 volumio sudo[2708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:24 volumio sudo[2706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:24 volumio sudo[2706]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:24.802Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4= ip6= Nov 03 10:10:24 volumio volumio[1128]: info: Received Get System Info Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 03 10:10:24 volumio volumio[1128]: info: Discovery: Getting this device information Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:10:24 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 03 10:10:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:24.851Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 03 10:10:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 03 10:10:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:24.890Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 03 10:10:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:24.891Z level=INFO msg="BLE descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:10:24 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:24.893Z level=INFO msg="mDNS descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:10:25 volumio sudo[2708]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:25 volumio wireless.js[2617]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: DE Nov 03 10:10:25 volumio sudo[2715]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 03 10:10:25 volumio sudo[2715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:25 volumio sudo[2715]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:25 volumio sudo[2717]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Nov 03 10:10:25 volumio sudo[2717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:25 volumio sudo[2717]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:25 volumio wireless.js[2617]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: DE Nov 03 10:10:25 volumio wireless.js[2617]: WIRELESS.JS: Start wireless flow Nov 03 10:10:25 volumio volumio[1128]: info: Discovery: Started advertising with name: Volumio Nov 03 10:10:25 volumio wireless.js[2617]: WIRELESS.JS: Stopped hotspot (if there).. Nov 03 10:10:25 volumio sudo[2726]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Nov 03 10:10:25 volumio sudo[2726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 03 10:10:25 volumio sudo[2726]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:25 volumio sudo[2730]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Nov 03 10:10:25 volumio sudo[2730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 03 10:10:26 volumio sudo[2730]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:26 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:26.092Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4= ip6= Nov 03 10:10:26 volumio volumio[1128]: info: Received Get System Info Nov 03 10:10:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 03 10:10:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 03 10:10:26 volumio volumio[1128]: info: Discovery: Getting this device information Nov 03 10:10:26 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Nov 03 10:10:26 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Nov 03 10:10:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 03 10:10:26 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:26.136Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 03 10:10:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 03 10:10:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 03 10:10:26 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:26.149Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 03 10:10:26 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:26.151Z level=INFO msg="BLE descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:10:26 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:26.155Z level=INFO msg="mDNS descriptor updated" deviceId=30a68afdda80d906539d2438fcb03de5 deviceName=Volumio deviceModel= Nov 03 10:10:26 volumio wireless.js[2617]: WIRELESS.JS: DHCP IP fallback Nov 03 10:10:26 volumio wireless.js[2617]: WIRELESS.JS: Start ap Nov 03 10:10:26 volumio sudo[2728]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 03 10:10:26 volumio sudo[2728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:26 volumio wpa_supplicant[2735]: Successfully initialized wpa_supplicant Nov 03 10:10:26 volumio sudo[2728]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:26 volumio sudo[2736]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Nov 03 10:10:26 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 03 10:10:26 volumio sudo[2736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 03 10:10:26 volumio dhcpcd[832]: control command: /sbin/dhcpcd Nov 03 10:10:26 volumio dhcpcd[832]: control_free: No such file or directory Nov 03 10:10:26 volumio sudo[2736]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:26 volumio dhcpcd[832]: lo: IAID 00:00:00:00 Nov 03 10:10:26 volumio dhcpcd[832]: lo: adding address fe80::ebaf:607:7cc8:b303 Nov 03 10:10:26 volumio dhcpcd[832]: ipv6_addaddr1: Permission denied Nov 03 10:10:26 volumio dhcpcd[832]: lo: using static address 127.0.0.1/8 Nov 03 10:10:26 volumio dhcpcd[832]: lo: adding route to 127.0.0.0/8 Nov 03 10:10:26 volumio systemd[1]: Reached target ip-changed@lo.target - IP Address changed on lo. Nov 03 10:10:26 volumio volumio[1128]: compat.c: read() failed: Resource temporarily unavailable Nov 03 10:10:26 volumio volumio[1128]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 03 10:10:26 volumio volumio[1128]: Error: dns service error: unknown Nov 03 10:10:26 volumio volumio[1128]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Nov 03 10:10:26 volumio volumio[1128]: errorCode: -65537 Nov 03 10:10:26 volumio volumio[1128]: } Nov 03 10:10:26 volumio volumio[1128]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 03 10:10:26 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:26.739Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4= ip6= Nov 03 10:10:27 volumio wpa_supplicant[2768]: wlan0: Trying to associate with 78:8a:20:d1:60:75 (SSID='Wesrau_Test2GHZ' freq=2462 MHz) Nov 03 10:10:27 volumio wpa_supplicant[2768]: wlan0: Associated with 78:8a:20:d1:60:75 Nov 03 10:10:27 volumio wpa_supplicant[2768]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Nov 03 10:10:27 volumio wpa_supplicant[2768]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Nov 03 10:10:27 volumio wireless.js[2617]: WIRELESS.JS: trying... Nov 03 10:10:27 volumio wpa_supplicant[2768]: wlan0: WPA: Key negotiation completed with 78:8a:20:d1:60:75 [PTK=CCMP GTK=CCMP] Nov 03 10:10:27 volumio wpa_supplicant[2768]: wlan0: CTRL-EVENT-CONNECTED - Connection to 78:8a:20:d1:60:75 completed [id=0 id_str=] Nov 03 10:10:27 volumio dhcpcd[832]: wlan0: carrier acquired Nov 03 10:10:27 volumio dhcpcd[832]: wlan0: connected to Access Point: Wesrau_Test2GHZ Nov 03 10:10:27 volumio dhcpcd[832]: wlan0: IAID eb:7a:d2:76 Nov 03 10:10:27 volumio sudo[2783]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 03 10:10:27 volumio sudo[2783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:27 volumio sudo[2783]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:27 volumio dhcpcd[832]: wlan0: soliciting a DHCP lease Nov 03 10:10:27 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:27.762Z level=DEBUG msg="network info updated" component=volumio/wifi ssid=Wesrau_Test2GHZ ip4= ip6= Nov 03 10:10:27 volumio kernel: hwmon hwmon1: Undervoltage detected! Nov 03 10:10:27 volumio dhcpcd[832]: wlan0: offered 192.168.1.6 from 192.168.1.1 Nov 03 10:10:27 volumio dhcpcd[832]: wlan0: soliciting an IPv6 router Nov 03 10:10:27 volumio dhcpcd[832]: wlan0: probing address 192.168.1.6/24 Nov 03 10:10:28 volumio wireless.js[2617]: WIRELESS.JS: trying... Nov 03 10:10:28 volumio sudo[2791]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 03 10:10:28 volumio sudo[2791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:28 volumio sudo[2791]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:28 volumio ntpd[955]: IO: Deleting interface #3 wlan0, 192.168.211.1#123, interface stats: received=0, sent=0, dropped=0, active_time=155 secs Nov 03 10:10:28 volumio ntpd[955]: IO: Deleting interface #5 wlan0, 169.254.246.173#123, interface stats: received=0, sent=0, dropped=0, active_time=96 secs Nov 03 10:10:29 volumio wireless.js[2617]: WIRELESS.JS: trying... Nov 03 10:10:29 volumio sudo[2795]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 03 10:10:29 volumio sudo[2795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:29 volumio sudo[2795]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:30 volumio wireless.js[2617]: WIRELESS.JS: trying... Nov 03 10:10:30 volumio sudo[2813]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 03 10:10:30 volumio sudo[2813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:30 volumio sudo[2813]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:31 volumio wireless.js[2617]: WIRELESS.JS: trying... Nov 03 10:10:31 volumio sudo[2817]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 03 10:10:31 volumio sudo[2817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:31 volumio sudo[2817]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:32 volumio wireless.js[2617]: WIRELESS.JS: trying... Nov 03 10:10:32 volumio sudo[2821]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 03 10:10:32 volumio sudo[2821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:32 volumio sudo[2821]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:33 volumio sudo[2826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-03 10:09' Nov 03 10:10:33 volumio dhcpcd[832]: wlan0: leased 192.168.1.6 for 86400 seconds Nov 03 10:10:33 volumio avahi-daemon[712]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.6. Nov 03 10:10:33 volumio avahi-daemon[712]: New relevant interface wlan0.IPv4 for mDNS. Nov 03 10:10:33 volumio avahi-daemon[712]: Registering new address record for 192.168.1.6 on wlan0.IPv4. Nov 03 10:10:33 volumio dhcpcd[832]: wlan0: adding route to 192.168.1.0/24 Nov 03 10:10:33 volumio dhcpcd[832]: wlan0: adding default route via 192.168.1.1 Nov 03 10:10:33 volumio sudo[2826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:33 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Nov 03 10:10:33 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Nov 03 10:10:33 volumio systemd[1]: welcome.service: Deactivated successfully. Nov 03 10:10:33 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Nov 03 10:10:33 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Nov 03 10:10:33 volumio wireless.js[2617]: WIRELESS.JS: trying... Nov 03 10:10:33 volumio sudo[2847]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 03 10:10:33 volumio sudo[2847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 03 10:10:33 volumio sudo[2847]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:33 volumio wireless.js[2617]: WIRELESS.JS: Connected to: ----Wesrau_Test2GHZ---- Nov 03 10:10:33 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Nov 03 10:10:33 volumio welcome[2845]: Resolved ip:[1] 192.168.1.6 Nov 03 10:10:33 volumio avahi-daemon[712]: Withdrawing address record for 127.0.0.1 on lo. Nov 03 10:10:33 volumio avahi-daemon[712]: Host name conflict, retrying with volumio-2 Nov 03 10:10:33 volumio avahi-daemon[712]: Registering new address record for 192.168.1.6 on wlan0.IPv4. Nov 03 10:10:33 volumio avahi-daemon[712]: Registering new address record for 127.0.0.1 on lo.IPv4. Nov 03 10:10:33 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:33.303Z level=WARN msg="Avahi server name collision detected, resetting service group" Nov 03 10:10:33 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Nov 03 10:10:33 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Nov 03 10:10:33 volumio sudo[2859]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 03 10:10:33 volumio sudo[2859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 03 10:10:33 volumio sudo[2859]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:33 volumio wireless.js[2617]: WIRELESS.JS: ... joined AP, wlan0 IPv4 is 192.168.1.6, ipV6 is undefined Nov 03 10:10:33 volumio wireless.js[2617]: WIRELESS.JS: It's done! AP Nov 03 10:10:33 volumio wireless.js[2617]: WIRELESS.JS: Restarting avahi-daemon... Nov 03 10:10:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 03 10:10:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 03 10:10:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:10:33 volumio systemd[1]: shairport-sync.service: Consumed 1.522s CPU time. Nov 03 10:10:33 volumio avahi-daemon[712]: Got SIGTERM, quitting. Nov 03 10:10:33 volumio avahi-daemon[712]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.6. Nov 03 10:10:33 volumio avahi-daemon[712]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Nov 03 10:10:33 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Nov 03 10:10:33 volumio dbus-daemon[714]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.34' (uid=0 pid=1184 comm="/usr/sbin/smbd --foreground --no-process-group") Nov 03 10:10:33 volumio avahi-daemon[712]: avahi-daemon 0.8 exiting. Nov 03 10:10:33 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Nov 03 10:10:33 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Nov 03 10:10:33 volumio wireless.js[2617]: WIRELESS.JS: Notified systemd about wireless ready Nov 03 10:10:33 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Nov 03 10:10:33 volumio avahi-daemon[2866]: Process 712 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Nov 03 10:10:33 volumio volumio5-onboarding[1678]: time=2025-11-03T09:10:33.661Z level=DEBUG msg="network info updated" component=volumio/wifi ssid=Wesrau_Test2GHZ ip4=192.168.1.6/24 ip6= Nov 03 10:10:33 volumio avahi-daemon[2866]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Nov 03 10:10:33 volumio avahi-daemon[2866]: Successfully dropped root privileges. Nov 03 10:10:33 volumio avahi-daemon[2866]: avahi-daemon 0.8 starting up. Nov 03 10:10:33 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 03 10:10:33 volumio dbus-daemon[714]: [system] Successfully activated service 'org.freedesktop.Avahi' Nov 03 10:10:33 volumio systemd[1]: Started wireless.service - Wireless Services. Nov 03 10:10:33 volumio avahi-daemon[2866]: Successfully called chroot(). Nov 03 10:10:33 volumio avahi-daemon[2866]: Successfully dropped remaining capabilities. Nov 03 10:10:33 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Nov 03 10:10:33 volumio avahi-daemon[2866]: No service file found in /etc/avahi/services. Nov 03 10:10:33 volumio avahi-daemon[2866]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.6. Nov 03 10:10:33 volumio avahi-daemon[2866]: New relevant interface wlan0.IPv4 for mDNS. Nov 03 10:10:33 volumio avahi-daemon[2866]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Nov 03 10:10:33 volumio avahi-daemon[2866]: New relevant interface lo.IPv4 for mDNS. Nov 03 10:10:33 volumio avahi-daemon[2866]: Network interface enumeration completed. Nov 03 10:10:33 volumio avahi-daemon[2866]: Registering new address record for 192.168.1.6 on wlan0.IPv4. Nov 03 10:10:33 volumio avahi-daemon[2866]: Registering new address record for 127.0.0.1 on lo.IPv4. Nov 03 10:10:33 volumio sudo[2614]: pam_unix(sudo:session): session closed for user root Nov 03 10:10:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 03 10:10:33 volumio avahi-daemon[2866]: Withdrawing address record for 192.168.1.6 on wlan0. Nov 03 10:10:33 volumio avahi-daemon[2866]: Host name conflict, retrying with volumio-2 Nov 03 10:10:33 volumio avahi-daemon[2866]: Registering new address record for 192.168.1.6 on wlan0.IPv4. Nov 03 10:10:33 volumio avahi-daemon[2866]: Registering new address record for 127.0.0.1 on lo.IPv4. Nov 03 10:10:34 volumio kernel: hwmon hwmon1: Voltage normalised PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="1bb44897f7ce359a55b9194fdfa5cb35d97fb06e" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="b5a4a000e056eaff366fbb6591bf2240b12246d0" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon Nov 3 09:07:40 UTC 2025" VOLUMIO_VERSION="4.064" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="55f2684742b79a5937291394763da14b"