Apr 15 13:49:00 volumio kernel: usb 3-1: New USB device found, idVendor=214b, idProduct=7000, bcdDevice= 1.00 Apr 15 13:49:00 volumio kernel: usb 3-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Apr 15 13:49:00 volumio kernel: usb 3-1: Product: USB2.0 HUB Apr 15 13:49:00 volumio kernel: hub 3-1:1.0: USB hub found Apr 15 13:49:00 volumio kernel: hub 3-1:1.0: 4 ports detected Apr 15 13:49:00 volumio kernel: usb usb3-port2: over-current change #71 Apr 15 13:49:00 volumio volumio[2924]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 15 13:49:00 volumio kernel: usb 3-2: USB disconnect, device number 72 Apr 15 13:49:00 volumio kernel: usb 3-2: new full-speed USB device number 74 using xhci-hcd Apr 15 13:49:00 volumio volumio[2924]: info: Updating MyVolumio device info Apr 15 13:49:00 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 13:49:00 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 13:49:00 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 13:49:00 volumio kernel: usb 3-2: New USB device found, idVendor=1a86, idProduct=e5e3, bcdDevice= 0.00 Apr 15 13:49:00 volumio kernel: usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 15 13:49:00 volumio kernel: usb 3-2: Product: USB2IIC_CTP_CONTROL Apr 15 13:49:00 volumio kernel: usb 3-2: Manufacturer: wch.cn Apr 15 13:49:00 volumio kernel: input: wch.cn USB2IIC_CTP_CONTROL as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-2/3-2:1.0/0003:1A86:E5E3.001F/input/input36 Apr 15 13:49:00 volumio kernel: hid-multitouch 0003:1A86:E5E3.001F: input,hidraw0: USB HID v1.00 Device [wch.cn USB2IIC_CTP_CONTROL] on usb-xhci-hcd.1-2/input0 Apr 15 13:49:01 volumio volumio[2924]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 15 13:49:02 volumio sudo[3658]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:03 volumio volumio[2924]: info: Received Get System Info Apr 15 13:49:03 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:49:03 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:49:03 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:49:03 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:03 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:03 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:49:03 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:49:03 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:49:03 volumio kernel: usb usb1-port1: over-current change #144 Apr 15 13:49:03 volumio kernel: usb usb3-port1: over-current change #80 Apr 15 13:49:03 volumio kernel: usb usb2-port1: over-current change #160 Apr 15 13:49:03 volumio kernel: usb usb4-port1: over-current change #160 Apr 15 13:49:03 volumio kernel: usb usb1-port2: over-current change #131 Apr 15 13:49:03 volumio kernel: usb 3-1: USB disconnect, device number 73 Apr 15 13:49:03 volumio volumio[2924]: info: AutoStart - Check #6/60 - VOLUMIO_SYSTEM_STATUS = starting Apr 15 13:49:03 volumio kernel: usb 3-1: new high-speed USB device number 75 using xhci-hcd Apr 15 13:49:04 volumio kernel: usb 3-1: New USB device found, idVendor=214b, idProduct=7000, bcdDevice= 1.00 Apr 15 13:49:04 volumio kernel: usb 3-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Apr 15 13:49:04 volumio kernel: usb 3-1: Product: USB2.0 HUB Apr 15 13:49:04 volumio kernel: hub 3-1:1.0: USB hub found Apr 15 13:49:04 volumio kernel: hub 3-1:1.0: 4 ports detected Apr 15 13:49:04 volumio kernel: usb usb3-port2: over-current change #72 Apr 15 13:49:04 volumio volumio5-onboarding[1731]: time=2026-04-15T13:49:04.144+09:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 15 13:49:04 volumio kernel: usb usb1-port1: over-current change #145 Apr 15 13:49:04 volumio kernel: usb 3-2: USB disconnect, device number 74 Apr 15 13:49:04 volumio kernel: usb usb2-port1: over-current change #161 Apr 15 13:49:04 volumio kernel: usb usb4-port1: over-current change #161 Apr 15 13:49:04 volumio kernel: usb usb1-port2: over-current change #132 Apr 15 13:49:04 volumio kernel: usb usb3-port1: over-current change #81 Apr 15 13:49:04 volumio kernel: usb 3-1: USB disconnect, device number 75 Apr 15 13:49:04 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 15 13:49:04 volumio volumio[2924]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Apr 15 13:49:04 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:04 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:04 volumio kernel: usb 3-1: new high-speed USB device number 76 using xhci-hcd Apr 15 13:49:04 volumio kernel: usb 3-1: New USB device found, idVendor=214b, idProduct=7000, bcdDevice= 1.00 Apr 15 13:49:04 volumio kernel: usb 3-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Apr 15 13:49:04 volumio kernel: usb 3-1: Product: USB2.0 HUB Apr 15 13:49:04 volumio kernel: hub 3-1:1.0: USB hub found Apr 15 13:49:04 volumio kernel: hub 3-1:1.0: 4 ports detected Apr 15 13:49:04 volumio kernel: usb usb3-port2: over-current change #73 Apr 15 13:49:05 volumio kernel: usb 3-2: new full-speed USB device number 77 using xhci-hcd Apr 15 13:49:05 volumio kernel: usb 3-2: New USB device found, idVendor=1a86, idProduct=e5e3, bcdDevice= 0.00 Apr 15 13:49:05 volumio kernel: usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 15 13:49:05 volumio kernel: usb 3-2: Product: USB2IIC_CTP_CONTROL Apr 15 13:49:05 volumio kernel: usb 3-2: Manufacturer: wch.cn Apr 15 13:49:05 volumio kernel: input: wch.cn USB2IIC_CTP_CONTROL as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-2/3-2:1.0/0003:1A86:E5E3.0020/input/input37 Apr 15 13:49:05 volumio kernel: hid-multitouch 0003:1A86:E5E3.0020: input,hidraw0: USB HID v1.00 Device [wch.cn USB2IIC_CTP_CONTROL] on usb-xhci-hcd.1-2/input0 Apr 15 13:49:08 volumio volumio[2924]: info: CoreCommandRouter::volumioGetVisibleSources Apr 15 13:49:08 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 13:49:08 volumio volumio[2924]: info: CoreCommandRouter::volumioGetQueue Apr 15 13:49:08 volumio volumio[2924]: info: CoreStateMachine::getQueue Apr 15 13:49:08 volumio volumio[2924]: info: CorePlayQueue::getQueue Apr 15 13:49:08 volumio volumio[2924]: info: AutoStart - Check #7/60 - VOLUMIO_SYSTEM_STATUS = starting Apr 15 13:49:08 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 13:49:08 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 13:49:08 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 15 13:49:09 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 15 13:49:09 volumio volumio-remote-updater[1021]: Test mode enabled Apr 15 13:49:09 volumio volumio-remote-updater[1021]: Alpha mode disabled Apr 15 13:49:09 volumio volumio-remote-updater[1021]: Alpha legacy test mode disabled Apr 15 13:49:09 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 13:49:09 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 13:49:09 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 15 13:49:09 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 15 13:49:09 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 15 13:49:09 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 15 13:49:09 volumio volumio[2924]: info: CoreCommandRouter::volumioGetBrowseSources Apr 15 13:49:09 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 13:49:09 volumio volumio[2924]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

NEW ADDITIONS

","title":"Update v4.119","updateavailable":true} Apr 15 13:49:09 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 15 13:49:10 volumio volumio[2924]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 15 13:49:10 volumio volumio[2924]: info: Completed starting MyVolumio Plugin Apr 15 13:49:10 volumio volumio[2924]: [Metrics] CommandRouter: 35s 381.95ms Apr 15 13:49:10 volumio volumio[2924]: info: CoreCommandRouter::volumiosetStartupVolume Apr 15 13:49:10 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 13:49:10 volumio volumio[2924]: info: VolumeController:: Setting startup Volume 70 Apr 15 13:49:10 volumio volumio[2924]: info: VolumeController::SetAlsaVolume70 Apr 15 13:49:10 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 15 13:49:10 volumio volumio[2924]: info: CoreCommandRouter::Close All Modals sent Apr 15 13:49:10 volumio volumio[2924]: info: CoreCommandRouter::Close All Modals sent Apr 15 13:49:10 volumio volumio[2924]: info: CoreStateMachine::pushState Apr 15 13:49:10 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:10 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 13:49:10 volumio volumio[2924]: info: CoreCommandRouter::volumioPushState Apr 15 13:49:10 volumio volumio[2924]: info: PeppyMeterBasic ---peppymeterbasic status stop Apr 15 13:49:10 volumio sudo[3694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Apr 15 13:49:10 volumio sudo[3694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:49:10 volumio sudo[3694]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:10 volumio volumio[2924]: info: peppymeterbasic Daemon Stop Apr 15 13:49:11 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 15 13:49:11 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 15 13:49:11 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 15 13:49:13 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 15 13:49:13 volumio volumio[2924]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 15 13:49:13 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 15 13:49:13 volumio volumio[2924]: info: Received Get System Version Apr 15 13:49:13 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 13:49:13 volumio volumio[2924]: info: Received Get System Info Apr 15 13:49:13 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:49:13 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:49:13 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:49:13 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:13 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:13 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:49:13 volumio volumio[2924]: info: AutoStart - Check #8/60 - VOLUMIO_SYSTEM_STATUS = starting Apr 15 13:49:17 volumio volumio[2924]: info: BOOT COMPLETED Apr 15 13:49:17 volumio volumio[2924]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 13:49:17 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 15 13:49:17 volumio volumio[2924]: info: mpdhttpout ---Boot completed detected! Patching mpd now! Apr 15 13:49:17 volumio volumio[2924]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Apr 15 13:49:17 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:17 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:17 volumio volumio[2924]: info: CoreCommandRouter::volumioPause Apr 15 13:49:17 volumio volumio[2924]: info: CoreStateMachine::pause Apr 15 13:49:17 volumio volumio[2924]: info: mpdhttpout --- Volumio set on pause Apr 15 13:49:17 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Apr 15 13:49:17 volumio sudo[3716]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Apr 15 13:49:17 volumio sudo[3727]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Apr 15 13:49:17 volumio sudo[3727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:49:17 volumio sudo[3716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:49:17 volumio sudo[3721]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Apr 15 13:49:17 volumio sudo[3727]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:17 volumio sudo[3721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:49:17 volumio sudo[3716]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:17 volumio sudo[3731]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Apr 15 13:49:17 volumio sudo[3721]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:17 volumio sudo[3731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:49:17 volumio sudo[3736]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 13:49:17 volumio sudo[3736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:49:17 volumio sudo[3739]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 13:49:17 volumio sudo[3739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:49:17 volumio sudo[3731]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:17 volumio sudo[3739]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:17 volumio sudo[3736]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:17 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Apr 15 13:49:17 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Apr 15 13:49:17 volumio sudo[3748]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 15 13:49:17 volumio sudo[3748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:49:17 volumio kernel: usb usb3-port1: over-current change #82 Apr 15 13:49:17 volumio kernel: usb usb1-port1: over-current change #146 Apr 15 13:49:17 volumio kernel: usb usb2-port1: over-current change #162 Apr 15 13:49:17 volumio kernel: usb usb4-port1: over-current change #162 Apr 15 13:49:17 volumio kernel: usb 3-1: USB disconnect, device number 76 Apr 15 13:49:17 volumio kernel: usb usb1-port2: over-current change #133 Apr 15 13:49:18 volumio kernel: usb 3-1: new high-speed USB device number 78 using xhci-hcd Apr 15 13:49:18 volumio kernel: usb 3-1: New USB device found, idVendor=214b, idProduct=7000, bcdDevice= 1.00 Apr 15 13:49:18 volumio kernel: usb 3-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Apr 15 13:49:18 volumio kernel: usb 3-1: Product: USB2.0 HUB Apr 15 13:49:18 volumio kernel: hub 3-1:1.0: USB hub found Apr 15 13:49:18 volumio kernel: hub 3-1:1.0: 4 ports detected Apr 15 13:49:18 volumio kernel: usb usb3-port2: over-current change #74 Apr 15 13:49:18 volumio kernel: usb 3-2: USB disconnect, device number 77 Apr 15 13:49:18 volumio kernel: usb 3-2: new full-speed USB device number 79 using xhci-hcd Apr 15 13:49:18 volumio volumio[2924]: info: AutoStart - Check #9/60 - VOLUMIO_SYSTEM_STATUS = ready Apr 15 13:49:18 volumio volumio[2924]: info: AutoStart - System ready state CONFIRMED after 9 checks Apr 15 13:49:18 volumio volumio[2924]: info: AutoStart - Applying additional delay of 20000ms before playback Apr 15 13:49:18 volumio kernel: usb 3-2: New USB device found, idVendor=1a86, idProduct=e5e3, bcdDevice= 0.00 Apr 15 13:49:18 volumio kernel: usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 15 13:49:18 volumio kernel: usb 3-2: Product: USB2IIC_CTP_CONTROL Apr 15 13:49:18 volumio kernel: usb 3-2: Manufacturer: wch.cn Apr 15 13:49:18 volumio kernel: input: wch.cn USB2IIC_CTP_CONTROL as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-2/3-2:1.0/0003:1A86:E5E3.0021/input/input38 Apr 15 13:49:18 volumio kernel: hid-multitouch 0003:1A86:E5E3.0021: input,hidraw0: USB HID v1.00 Device [wch.cn USB2IIC_CTP_CONTROL] on usb-xhci-hcd.1-2/input0 Apr 15 13:49:19 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Apr 15 13:49:19 volumio sudo[3760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 15 13:49:19 volumio sudo[3760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:49:19 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 15 13:49:19 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 15 13:49:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 15 13:49:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 15 13:49:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 15 13:49:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 15 13:49:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 15 13:49:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 15 13:49:19 volumio sudo[3763]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 15 13:49:19 volumio sudo[3763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 13:49:19 volumio sudo[3763]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:20 volumio mpd[3765]: 2026-04-15T13:49:20 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 15 13:49:20 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 15 13:49:20 volumio sudo[3760]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:20 volumio volumio[2924]: error: updateQueue error: null Apr 15 13:49:20 volumio sudo[3748]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:20 volumio volumio[2924]: info: Received Get System Info Apr 15 13:49:20 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:49:20 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:49:20 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:49:20 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:20 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:20 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:49:20 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:49:20 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:49:21 volumio volumio5-onboarding[1731]: time=2026-04-15T13:49:21.721+09:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 15 13:49:37 volumio dhcpcd[1057]: eth0: carrier lost Apr 15 13:49:37 volumio kernel: macb 1f00100000.ethernet eth0: Link is Down Apr 15 13:49:37 volumio avahi-daemon[991]: Withdrawing address record for 192.168.0.38 on eth0. Apr 15 13:49:37 volumio avahi-daemon[991]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.0.38. Apr 15 13:49:37 volumio avahi-daemon[991]: Interface eth0.IPv4 no longer relevant for mDNS. Apr 15 13:49:37 volumio dhcpcd[1057]: eth0: deleting route to 192.168.0.0/24 Apr 15 13:49:37 volumio dhcpcd[1057]: eth0: deleting default route via 192.168.0.1 Apr 15 13:49:37 volumio volumio[2924]: info: Discovery: A device disappeared from network Apr 15 13:49:37 volumio volumio[2924]: info: Discovery: Device volumio disappeared from network Apr 15 13:49:37 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Apr 15 13:49:37 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Apr 15 13:49:37 volumio systemd[1]: welcome.service: Deactivated successfully. Apr 15 13:49:37 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 15 13:49:37 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 15 13:49:37 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 15 13:49:37 volumio welcome[3822]: Resolved ip:[0] Apr 15 13:49:37 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 15 13:49:37 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Apr 15 13:49:37 volumio volumio[2924]: info: Received Get System Info Apr 15 13:49:37 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:49:37 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:49:37 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:49:37 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:37 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:37 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:49:37 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:49:37 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:49:37 volumio ifplugd(eth0)[1270]: Link beat lost. Apr 15 13:49:38 volumio volumio5-onboarding[1731]: time=2026-04-15T13:49:38.546+09:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 15 13:49:38 volumio ntpd[1199]: IO: Deleting interface #4 eth0, 192.168.0.38#123, interface stats: received=74, sent=75, dropped=6, active_time=50 secs Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 158.247.239.209 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 158.247.202.103 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 194.0.5.123 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 211.108.117.211 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 203.32.26.46 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 193.123.243.2 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 121.134.215.104 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 175.210.18.47 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 175.195.167.194 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 121.174.142.82 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 121.174.142.81 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio ntpd[1199]: PROTO: 3.39.176.65 unlink local addr 192.168.0.38 -> Apr 15 13:49:38 volumio volumio[2924]: info: AutoStart - startPlayback called Apr 15 13:49:38 volumio volumio[2924]: info: CoreCommandRouter::volumioGetQueue Apr 15 13:49:38 volumio volumio[2924]: info: CoreStateMachine::getQueue Apr 15 13:49:38 volumio volumio[2924]: info: CorePlayQueue::getQueue Apr 15 13:49:38 volumio volumio[2924]: info: AutoStart - Queue is empty, nothing to play Apr 15 13:49:45 volumio volumio[2924]: info: Volumio Network Manager: Network status updated: 0 Apr 15 13:49:47 volumio ifplugd(eth0)[1270]: Executing '/etc/ifplugd/ifplugd.action eth0 down'. Apr 15 13:49:47 volumio ifplugd(eth0)[1270]: client: dhcpcd not running Apr 15 13:49:47 volumio dhcpcd[3851]: dhcpcd not running Apr 15 13:49:47 volumio kernel: macb 1f00100000.ethernet: gem-ptp-timer ptp clock unregistered. Apr 15 13:49:47 volumio ifplugd(eth0)[1270]: Program executed successfully. Apr 15 13:49:47 volumio kernel: macb 1f00100000.ethernet eth0: PHY [1f00100000.ethernet-ffffffff:01] driver [Broadcom BCM54213PE] (irq=POLL) Apr 15 13:49:47 volumio kernel: macb 1f00100000.ethernet eth0: configuring for phy/rgmii-id link mode Apr 15 13:49:47 volumio kernel: macb 1f00100000.ethernet: gem-ptp-timer ptp clock registered. Apr 15 13:49:48 volumio volumio[2924]: info: Received Get System Info Apr 15 13:49:48 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:49:48 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:49:48 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:49:48 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:48 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:48 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:49:48 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:49:48 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:49:48 volumio wireless.js[1024]: WIRELESS.JS - INFO: === SNM TRANSITION === Apr 15 13:49:48 volumio wireless.js[1024]: WIRELESS.JS - INFO: Previous ethernet state: connected Apr 15 13:49:48 volumio wireless.js[1024]: WIRELESS.JS - INFO: New ethernet state: disconnected Apr 15 13:49:48 volumio wireless.js[1024]: WIRELESS.JS - INFO: Single Network Mode: enabled Apr 15 13:49:48 volumio wireless.js[1024]: WIRELESS.JS - INFO: First start: no Apr 15 13:49:48 volumio wireless.js[1024]: WIRELESS.JS - INFO: Action: Reconnect WiFi Apr 15 13:49:48 volumio wireless.js[1024]: WIRELESS.JS - INFO: === END TRANSITION === Apr 15 13:49:48 volumio sudo[3870]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 15 13:49:48 volumio sudo[3870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:49:48 volumio sudo[3870]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:48 volumio wireless.js[1024]: WIRELESS.JS - INFO: SNM: Ethernet disconnected, reconnecting WiFi Apr 15 13:49:48 volumio wireless.js[1024]: WIRELESS.JS - INFO: SNM: Ethernet disconnected, reconnecting WiFi Apr 15 13:49:48 volumio wireless.js[1024]: WIRELESS.JS - INFO: reconnectWiFi: WiFi reconnection triggered Apr 15 13:49:49 volumio volumio5-onboarding[1731]: time=2026-04-15T13:49:49.113+09:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 15 13:49:51 volumio wpa_supplicant[3475]: wlan0: Trying to associate with b2:eb:b6:c0:1c:0b (SSID='sall8982' freq=5785 MHz) Apr 15 13:49:51 volumio wpa_supplicant[3475]: wlan0: Associated with b2:eb:b6:c0:1c:0b Apr 15 13:49:51 volumio wpa_supplicant[3475]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 15 13:49:51 volumio wpa_supplicant[3475]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Apr 15 13:49:51 volumio wpa_supplicant[3475]: wlan0: WPA: Key negotiation completed with b2:eb:b6:c0:1c:0b [PTK=CCMP GTK=CCMP] Apr 15 13:49:51 volumio wpa_supplicant[3475]: wlan0: CTRL-EVENT-CONNECTED - Connection to b2:eb:b6:c0:1c:0b completed [id=0 id_str=] Apr 15 13:49:51 volumio dhcpcd[1057]: wlan0: carrier acquired Apr 15 13:49:51 volumio dhcpcd[1057]: wlan0: connected to Access Point: sall8982 Apr 15 13:49:51 volumio dhcpcd[1057]: wlan0: IAID 67:04:16:3f Apr 15 13:49:51 volumio wireless.js[1024]: WIRELESS.JS - INFO: reconnectWiFi: WiFi reconnected successfully Apr 15 13:49:51 volumio wireless.js[1024]: WIRELESS.JS - INFO: reconnectWiFi: Using DHCP for IP Apr 15 13:49:51 volumio wireless.js[1024]: WIRELESS.JS - INFO: SNM: WiFi reconnection completed in 3058ms Apr 15 13:49:51 volumio wireless.js[1024]: WIRELESS.JS - INFO: reconnectWiFi: WiFi reconnection complete, obtaining IP Apr 15 13:49:51 volumio sudo[3885]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd wlan0 Apr 15 13:49:51 volumio wireless.js[1024]: WIRELESS.JS - INFO: Restarting avahi-daemon... Apr 15 13:49:51 volumio sudo[3885]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 13:49:51 volumio dhcpcd[1057]: ps_ctl_dispatch: cannot handle another client Apr 15 13:49:51 volumio kernel: usb usb3-port1: over-current change #83 Apr 15 13:49:51 volumio kernel: usb usb1-port1: over-current change #147 Apr 15 13:49:51 volumio dhcpcd[1057]: control_free: No such file or directory Apr 15 13:49:51 volumio sudo[3885]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:51 volumio sudo[3890]: root : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart avahi-daemon Apr 15 13:49:51 volumio sudo[3890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 13:49:51 volumio kernel: usb usb4-port1: over-current change #163 Apr 15 13:49:51 volumio kernel: usb usb2-port1: over-current change #163 Apr 15 13:49:51 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 15 13:49:51 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 15 13:49:51 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 15 13:49:51 volumio systemd[1]: shairport-sync.service: Consumed 1.634s CPU time. Apr 15 13:49:51 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Apr 15 13:49:51 volumio avahi-daemon[991]: Got SIGTERM, quitting. Apr 15 13:49:51 volumio avahi-daemon[991]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Apr 15 13:49:51 volumio volumio[2924]: error: Discovery: Advertisement error: Error: dns service error: unknown Apr 15 13:49:51 volumio volumio[2924]: error: Discovery: advertisement error: Error: dns service error: unknown Apr 15 13:49:51 volumio volumio[2924]: info: Discovery: Advertisement raised the following error Error: dns service error: unknown Apr 15 13:49:51 volumio volumio[2924]: info: Discovery: Stopping Advertising Immediately Apr 15 13:49:51 volumio volumio[2924]: info: Discovery: Stopping existing advertisement Apr 15 13:49:51 volumio volumio[2924]: info: Discovery: Browse raised the following error Error: dns service error: unknown Apr 15 13:49:51 volumio volumio[2924]: info: Discovery: Restarting Browsing Apr 15 13:49:51 volumio dbus-daemon[999]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.42' (uid=0 pid=1986 comm="/usr/sbin/smbd --foreground --no-process-group") Apr 15 13:49:51 volumio avahi-daemon[991]: avahi-daemon 0.8 exiting. Apr 15 13:49:51 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Apr 15 13:49:51 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Apr 15 13:49:51 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Apr 15 13:49:51 volumio avahi-daemon[3896]: Process 991 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Apr 15 13:49:51 volumio avahi-daemon[3896]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Apr 15 13:49:51 volumio avahi-daemon[3896]: Successfully dropped root privileges. Apr 15 13:49:51 volumio avahi-daemon[3896]: avahi-daemon 0.8 starting up. Apr 15 13:49:51 volumio dbus-daemon[999]: [system] Successfully activated service 'org.freedesktop.Avahi' Apr 15 13:49:51 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Apr 15 13:49:51 volumio avahi-daemon[3896]: Successfully called chroot(). Apr 15 13:49:51 volumio avahi-daemon[3896]: Successfully dropped remaining capabilities. Apr 15 13:49:51 volumio avahi-daemon[3896]: No service file found in /etc/avahi/services. Apr 15 13:49:51 volumio avahi-daemon[3896]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Apr 15 13:49:51 volumio avahi-daemon[3896]: New relevant interface lo.IPv4 for mDNS. Apr 15 13:49:51 volumio avahi-daemon[3896]: Network interface enumeration completed. Apr 15 13:49:51 volumio avahi-daemon[3896]: Registering new address record for 127.0.0.1 on lo.IPv4. Apr 15 13:49:51 volumio sudo[3890]: pam_unix(sudo:session): session closed for user root Apr 15 13:49:51 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 15 13:49:52 volumio kernel: usb 3-1: USB disconnect, device number 78 Apr 15 13:49:52 volumio kernel: usb usb1-port2: over-current change #134 Apr 15 13:49:52 volumio kernel: usb 3-1: new high-speed USB device number 80 using xhci-hcd Apr 15 13:49:52 volumio dhcpcd[1057]: wlan0: soliciting an IPv6 router Apr 15 13:49:52 volumio volumio[2924]: info: Received Get System Info Apr 15 13:49:52 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:49:52 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:49:52 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:49:52 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:52 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:52 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:49:52 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:49:52 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:49:52 volumio kernel: usb 3-1: New USB device found, idVendor=214b, idProduct=7000, bcdDevice= 1.00 Apr 15 13:49:52 volumio kernel: usb 3-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Apr 15 13:49:52 volumio kernel: usb 3-1: Product: USB2.0 HUB Apr 15 13:49:52 volumio kernel: hub 3-1:1.0: USB hub found Apr 15 13:49:52 volumio kernel: hub 3-1:1.0: 4 ports detected Apr 15 13:49:52 volumio kernel: usb usb3-port2: over-current change #75 Apr 15 13:49:52 volumio kernel: usb 3-2: USB disconnect, device number 79 Apr 15 13:49:52 volumio kernel: usb 3-2: new full-speed USB device number 81 using xhci-hcd Apr 15 13:49:52 volumio avahi-daemon[3896]: Server startup complete. Host name is volumio.local. Local service cookie is 3852976000. Apr 15 13:49:52 volumio dhcpcd[1057]: wlan0: soliciting a DHCP lease Apr 15 13:49:53 volumio kernel: usb 3-2: New USB device found, idVendor=1a86, idProduct=e5e3, bcdDevice= 0.00 Apr 15 13:49:53 volumio kernel: usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 15 13:49:53 volumio kernel: usb 3-2: Product: USB2IIC_CTP_CONTROL Apr 15 13:49:53 volumio kernel: usb 3-2: Manufacturer: wch.cn Apr 15 13:49:53 volumio kernel: input: wch.cn USB2IIC_CTP_CONTROL as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-2/3-2:1.0/0003:1A86:E5E3.0022/input/input39 Apr 15 13:49:53 volumio kernel: hid-multitouch 0003:1A86:E5E3.0022: input,hidraw0: USB HID v1.00 Device [wch.cn USB2IIC_CTP_CONTROL] on usb-xhci-hcd.1-2/input0 Apr 15 13:49:53 volumio volumio5-onboarding[1731]: time=2026-04-15T13:49:53.853+09:00 level=ERROR msg="failed to read from connection" component=conn/multi error="http: Server closed" Apr 15 13:49:53 volumio volumio5-onboarding[1731]: time=2026-04-15T13:49:53.853+09:00 level=INFO msg="connection closed, stopping read loop" component=conn/multi net=ws+tcp addr=[::]:7331 Apr 15 13:49:53 volumio volumio5-onboarding[1731]: time=2026-04-15T13:49:53.858+09:00 level=INFO msg="connection closed, stopping read loop" component=conn/multi net=ble addr=2C:CF:67:04:16:40%00 Apr 15 13:49:53 volumio volumio5-onboarding[1731]: failed to run app: failed to run mDNS advertiser: failed to connect to Avahi daemon: avahi: Daemon connection failed Apr 15 13:49:53 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Apr 15 13:49:53 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Apr 15 13:49:53 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Apr 15 13:49:53 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 15 13:49:54 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Apr 15 13:49:54 volumio volumio5-onboarding[3922]: time=2026-04-15T13:49:54.045+09:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Apr 15 13:49:54 volumio volumio[2924]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 11 Apr 15 13:49:54 volumio volumio[2924]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 11 Apr 15 13:49:54 volumio volumio[2924]: info: Received Get System Info Apr 15 13:49:54 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:49:54 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:49:54 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:49:54 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:54 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:54 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:49:54 volumio volumio5-onboarding[3922]: time=2026-04-15T13:49:54.061+09:00 level=INFO msg="system info for 078666b915fb561fe7c761a01d2a8e2d" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.097 Apr 15 13:49:54 volumio volumio[2924]: info: Received Get System Info Apr 15 13:49:54 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:49:54 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:49:54 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:49:54 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:54 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:54 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:49:54 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:49:54 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:49:54 volumio volumio5-onboarding[3922]: time=2026-04-15T13:49:54.069+09:00 level=INFO msg="enabling local network discovery" Apr 15 13:49:54 volumio volumio5-onboarding[3922]: time=2026-04-15T13:49:54.076+09:00 level=INFO msg="enabling BLE discovery" Apr 15 13:49:54 volumio volumio5-onboarding[3922]: time=2026-04-15T13:49:54.094+09:00 level=INFO msg="bootstrapping state" hasInternet=false Apr 15 13:49:55 volumio volumio5-onboarding[3922]: time=2026-04-15T13:49:55.031+09:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 15 13:49:56 volumio dhcpcd[1057]: wlan0: offered 192.168.0.39 from 192.168.0.1 Apr 15 13:49:56 volumio dhcpcd[1057]: wlan0: probing address 192.168.0.39/24 Apr 15 13:49:56 volumio volumio[2924]: info: Discovery: Restarting Advertising Apr 15 13:49:56 volumio nmbd[1297]: [2026/04/15 13:49:56.948770, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Apr 15 13:49:56 volumio nmbd[1297]: Packet send failed to 192.168.0.255(138) ERRNO=Network is unreachable Apr 15 13:49:59 volumio dhcpcd[1057]: eth0: carrier acquired Apr 15 13:49:59 volumio kernel: macb 1f00100000.ethernet eth0: Link is Up - 100Mbps/Full - flow control off Apr 15 13:49:59 volumio dhcpcd[1057]: eth0: IAID 67:04:16:3e Apr 15 13:49:59 volumio dhcpcd[1057]: eth0: rebinding lease of 192.168.0.38 Apr 15 13:49:59 volumio dhcpcd[1057]: eth0: probing address 192.168.0.38/24 Apr 15 13:49:59 volumio dhcpcd[1057]: eth0: soliciting an IPv6 router Apr 15 13:49:59 volumio volumio[2924]: info: Received Get System Info Apr 15 13:49:59 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:49:59 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:49:59 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:49:59 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:49:59 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:49:59 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:49:59 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:49:59 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:49:59 volumio ifplugd(eth0)[1270]: Link beat detected. Apr 15 13:49:59 volumio ifplugd(eth0)[1270]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Apr 15 13:49:59 volumio ifplugd(eth0)[1270]: client: sending commands to dhcpcd process Apr 15 13:49:59 volumio dhcpcd[1057]: ps_ctl_dispatch: cannot handle another client Apr 15 13:49:59 volumio dhcpcd[1057]: control_free: No such file or directory Apr 15 13:50:00 volumio ifplugd(eth0)[1270]: Program executed successfully. Apr 15 13:50:00 volumio volumio5-onboarding[3922]: time=2026-04-15T13:50:00.556+09:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 15 13:50:00 volumio dhcpcd[1057]: wlan0: leased 192.168.0.39 for 7200 seconds Apr 15 13:50:00 volumio avahi-daemon[3896]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.39. Apr 15 13:50:00 volumio avahi-daemon[3896]: New relevant interface wlan0.IPv4 for mDNS. Apr 15 13:50:00 volumio avahi-daemon[3896]: Registering new address record for 192.168.0.39 on wlan0.IPv4. Apr 15 13:50:00 volumio dhcpcd[1057]: wlan0: adding route to 192.168.0.0/24 Apr 15 13:50:00 volumio dhcpcd[1057]: wlan0: adding default route via 192.168.0.1 Apr 15 13:50:00 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 15 13:50:00 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Apr 15 13:50:00 volumio systemd[1]: welcome.service: Deactivated successfully. Apr 15 13:50:00 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 15 13:50:00 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 15 13:50:00 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 15 13:50:00 volumio welcome[4018]: Resolved ip:[1] 192.168.0.39 Apr 15 13:50:00 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 15 13:50:00 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 15 13:50:00 volumio wireless.js[1024]: WIRELESS.JS - INFO: === SNM TRANSITION === Apr 15 13:50:00 volumio wireless.js[1024]: WIRELESS.JS - INFO: Previous ethernet state: disconnected Apr 15 13:50:00 volumio wireless.js[1024]: WIRELESS.JS - INFO: New ethernet state: connected Apr 15 13:50:00 volumio wireless.js[1024]: WIRELESS.JS - INFO: Single Network Mode: enabled Apr 15 13:50:00 volumio wireless.js[1024]: WIRELESS.JS - INFO: First start: no Apr 15 13:50:00 volumio wireless.js[1024]: WIRELESS.JS - INFO: Action: Switch to ethernet (WiFi scan mode) Apr 15 13:50:00 volumio wireless.js[1024]: WIRELESS.JS - INFO: === END TRANSITION === Apr 15 13:50:00 volumio wireless.js[1024]: WIRELESS.JS - INFO: SNM: Ethernet connected, switching to ethernet (WiFi scan mode) Apr 15 13:50:00 volumio sudo[4034]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd -k wlan0 Apr 15 13:50:00 volumio sudo[4034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 13:50:00 volumio dhcpcd[4035]: dhcpcd not running Apr 15 13:50:00 volumio sudo[4034]: pam_unix(sudo:session): session closed for user root Apr 15 13:50:00 volumio wireless.js[1024]: dhcpcd not running Apr 15 13:50:00 volumio wireless.js[1024]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Apr 15 13:50:01 volumio wpa_supplicant[3475]: p2p-dev-wlan0: CTRL-EVENT-DSCP-POLICY clear_all Apr 15 13:50:01 volumio wpa_supplicant[3475]: p2p-dev-wlan0: CTRL-EVENT-DSCP-POLICY clear_all Apr 15 13:50:01 volumio wpa_supplicant[3475]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0 Apr 15 13:50:01 volumio wpa_supplicant[3475]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING Apr 15 13:50:01 volumio wpa_supplicant[3475]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b2:eb:b6:c0:1c:0b reason=3 locally_generated=1 Apr 15 13:50:01 volumio dhcpcd[1057]: wlan0: carrier lost - roaming Apr 15 13:50:01 volumio dhcpcd[1057]: wlan0: changing route to 192.168.0.0/24 Apr 15 13:50:01 volumio dhcpcd[1057]: wlan0: changing default route via 192.168.0.1 Apr 15 13:50:01 volumio wpa_supplicant[3475]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Apr 15 13:50:01 volumio sudo[4043]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 15 13:50:01 volumio sudo[4043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 13:50:01 volumio avahi-daemon[3896]: Withdrawing address record for 192.168.0.39 on wlan0. Apr 15 13:50:01 volumio avahi-daemon[3896]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.39. Apr 15 13:50:01 volumio avahi-daemon[3896]: Interface wlan0.IPv4 no longer relevant for mDNS. Apr 15 13:50:01 volumio sudo[4043]: pam_unix(sudo:session): session closed for user root Apr 15 13:50:01 volumio dhcpcd[1057]: wlan0: pid 4052 deleted IP address 192.168.0.39/24 Apr 15 13:50:01 volumio dhcpcd[1057]: wlan0: deleting route to 192.168.0.0/24 Apr 15 13:50:01 volumio wpa_supplicant[3475]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Apr 15 13:50:01 volumio wpa_supplicant[3475]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Apr 15 13:50:01 volumio dhcpcd[1057]: wlan0: deleting default route via 192.168.0.1 Apr 15 13:50:01 volumio sudo[4060]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 15 13:50:01 volumio sudo[4060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 13:50:01 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 15 13:50:01 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Apr 15 13:50:01 volumio systemd[1]: welcome.service: Deactivated successfully. Apr 15 13:50:01 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 15 13:50:01 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 15 13:50:01 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 15 13:50:01 volumio dhcpcd[1057]: wlan0: waiting for carrier Apr 15 13:50:01 volumio wpa_supplicant[3475]: wlan0: CTRL-EVENT-TERMINATING Apr 15 13:50:01 volumio dhcpcd[1057]: wlan0: carrier lost Apr 15 13:50:01 volumio welcome[4073]: Resolved ip:[0] Apr 15 13:50:01 volumio sudo[4060]: pam_unix(sudo:session): session closed for user root Apr 15 13:50:01 volumio volumio[2924]: info: Received Get System Info Apr 15 13:50:01 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:50:01 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:50:01 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:50:01 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:50:01 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:50:01 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:50:01 volumio wireless.js[1024]: WIRELESS.JS - INFO: Cleaning previous... Apr 15 13:50:01 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:50:01 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:50:01 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 15 13:50:01 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Apr 15 13:50:01 volumio sudo[4082]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 15 13:50:01 volumio kernel: usb usb3-port1: over-current change #84 Apr 15 13:50:01 volumio kernel: usb usb1-port1: over-current change #148 Apr 15 13:50:01 volumio sudo[4082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 13:50:01 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 15 13:50:01 volumio sudo[4082]: pam_unix(sudo:session): session closed for user root Apr 15 13:50:01 volumio kernel: usb usb2-port1: over-current change #164 Apr 15 13:50:01 volumio kernel: usb usb4-port1: over-current change #164 Apr 15 13:50:01 volumio kernel: usb 3-1: USB disconnect, device number 80 Apr 15 13:50:01 volumio kernel: usb usb1-port2: over-current change #135 Apr 15 13:50:01 volumio volumio[2924]: info: Discovery: Started advertising with name: Volumio Apr 15 13:50:02 volumio kernel: usb 3-1: new high-speed USB device number 82 using xhci-hcd Apr 15 13:50:02 volumio volumio[2924]: info: Received Get System Info Apr 15 13:50:02 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:50:02 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:50:02 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:50:02 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:50:02 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:50:02 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:50:02 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:50:02 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:50:02 volumio kernel: usb 3-1: New USB device found, idVendor=214b, idProduct=7000, bcdDevice= 1.00 Apr 15 13:50:02 volumio kernel: usb 3-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Apr 15 13:50:02 volumio kernel: usb 3-1: Product: USB2.0 HUB Apr 15 13:50:02 volumio kernel: hub 3-1:1.0: USB hub found Apr 15 13:50:02 volumio kernel: hub 3-1:1.0: 4 ports detected Apr 15 13:50:02 volumio kernel: usb usb3-port2: over-current change #76 Apr 15 13:50:02 volumio kernel: usb 3-2: USB disconnect, device number 81 Apr 15 13:50:02 volumio kernel: usb 3-2: new full-speed USB device number 83 using xhci-hcd Apr 15 13:50:02 volumio kernel: usb 3-2: New USB device found, idVendor=1a86, idProduct=e5e3, bcdDevice= 0.00 Apr 15 13:50:02 volumio kernel: usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 15 13:50:02 volumio kernel: usb 3-2: Product: USB2IIC_CTP_CONTROL Apr 15 13:50:02 volumio kernel: usb 3-2: Manufacturer: wch.cn Apr 15 13:50:02 volumio volumio[2924]: info: Discovery: adding 3e7288d2-d3cc-49d4-8a70-86a1259986b4 Apr 15 13:50:02 volumio volumio[2924]: info: Discovery: Found device Volumio Apr 15 13:50:02 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:50:02 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:50:02 volumio kernel: input: wch.cn USB2IIC_CTP_CONTROL as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-2/3-2:1.0/0003:1A86:E5E3.0023/input/input40 Apr 15 13:50:02 volumio kernel: hid-multitouch 0003:1A86:E5E3.0023: input,hidraw0: USB HID v1.00 Device [wch.cn USB2IIC_CTP_CONTROL] on usb-xhci-hcd.1-2/input0 Apr 15 13:50:03 volumio wireless.js[1024]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Apr 15 13:50:03 volumio wireless.js[1024]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 1ms Apr 15 13:50:03 volumio wireless.js[1024]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: 2c:cf:67:04:16:3f) Apr 15 13:50:03 volumio sudo[4109]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Apr 15 13:50:03 volumio sudo[4109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:50:03 volumio sudo[4109]: pam_unix(sudo:session): session closed for user root Apr 15 13:50:03 volumio sudo[4117]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Apr 15 13:50:03 volumio sudo[4117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 15 13:50:03 volumio volumio5-onboarding[3922]: time=2026-04-15T13:50:03.482+09:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 15 13:50:04 volumio dhcpcd[1057]: eth0: leased 192.168.0.38 for infinity Apr 15 13:50:04 volumio avahi-daemon[3896]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.38. Apr 15 13:50:04 volumio avahi-daemon[3896]: New relevant interface eth0.IPv4 for mDNS. Apr 15 13:50:04 volumio avahi-daemon[3896]: Registering new address record for 192.168.0.38 on eth0.IPv4. Apr 15 13:50:04 volumio dhcpcd[1057]: eth0: adding route to 192.168.0.0/24 Apr 15 13:50:04 volumio dhcpcd[1057]: eth0: adding default route via 192.168.0.1 Apr 15 13:50:04 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Apr 15 13:50:04 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Apr 15 13:50:04 volumio systemd[1]: welcome.service: Deactivated successfully. Apr 15 13:50:04 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 15 13:50:04 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 15 13:50:04 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 15 13:50:04 volumio welcome[4145]: Resolved ip:[1] 192.168.0.38 Apr 15 13:50:04 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 15 13:50:04 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Apr 15 13:50:04 volumio volumio[2924]: info: Received Get System Info Apr 15 13:50:04 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:50:04 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:50:04 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:50:04 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:50:04 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:50:04 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:50:04 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:50:04 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:50:05 volumio volumio[2924]: info: Discovery: this is already registered, 3e7288d2-d3cc-49d4-8a70-86a1259986b4 Apr 15 13:50:05 volumio volumio[2924]: info: Discovery: Found device Volumio Apr 15 13:50:05 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:50:05 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:50:05 volumio volumio[2924]: info: Volumio Network Manager: Network status updated: 1 Apr 15 13:50:05 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: personal_radio , handleBrowseUri Apr 15 13:50:05 volumio volumio[2924]: info: Preload queue cleared Apr 15 13:50:05 volumio volumio5-onboarding[3922]: time=2026-04-15T13:50:05.563+09:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 15 13:50:05 volumio ntpd[1199]: IO: Listen normally on 5 eth0 192.168.0.38:123 Apr 15 13:50:05 volumio ntpd[1199]: IO: new interface(s) found: waking up resolver Apr 15 13:50:06 volumio sudo[4117]: pam_unix(sudo:session): session closed for user root Apr 15 13:50:06 volumio wireless.js[1024]: WIRELESS.JS - INFO: Regdomain already correct: US Apr 15 13:50:06 volumio wireless.js[1024]: WIRELESS.JS - INFO: Single Network Mode: Ethernet active, maintaining WiFi scan capability Apr 15 13:50:06 volumio wireless.js[1024]: WIRELESS.JS - INFO: SNM: Maintaining wlan0 UP without IP (scan mode) Apr 15 13:50:06 volumio wireless.js[1024]: WIRELESS.JS - INFO: SNM: Users can configure WiFi via WebUI while ethernet is active Apr 15 13:50:06 volumio sudo[4179]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 15 13:50:06 volumio sudo[4179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 13:50:06 volumio sudo[4179]: pam_unix(sudo:session): session closed for user root Apr 15 13:50:06 volumio sudo[4182]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 15 13:50:06 volumio sudo[4182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 15 13:50:06 volumio sudo[4182]: pam_unix(sudo:session): session closed for user root Apr 15 13:50:06 volumio wpa_supplicant[4185]: Successfully initialized wpa_supplicant Apr 15 13:50:06 volumio wpa_supplicant[4185]: nl80211: kernel reports: Registration to specific type not supported Apr 15 13:50:06 volumio wpa_supplicant[4188]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Apr 15 13:50:06 volumio wireless.js[1024]: WIRELESS.JS - INFO: SNM: Transition to scan mode completed in 5212ms Apr 15 13:50:06 volumio wireless.js[1024]: WIRELESS.JS - INFO: SNM: wlan0 is UP without IP, scan capable Apr 15 13:50:06 volumio kernel: usb usb3-port1: over-current change #85 Apr 15 13:50:06 volumio kernel: usb usb1-port1: over-current change #149 Apr 15 13:50:06 volumio wireless.js[1024]: WIRELESS.JS - INFO: Notified systemd about wireless ready Apr 15 13:50:06 volumio kernel: usb usb4-port1: over-current change #165 Apr 15 13:50:06 volumio kernel: usb usb2-port1: over-current change #165 Apr 15 13:50:06 volumio kernel: usb 3-1: USB disconnect, device number 82 Apr 15 13:50:06 volumio kernel: usb usb1-port2: over-current change #136 Apr 15 13:50:06 volumio kernel: usb 3-1: new high-speed USB device number 84 using xhci-hcd Apr 15 13:50:06 volumio volumio[2924]: info: Received Get System Info Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:50:06 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:50:06 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 15 13:50:06 volumio kernel: usb 3-1: New USB device found, idVendor=214b, idProduct=7000, bcdDevice= 1.00 Apr 15 13:50:06 volumio kernel: usb 3-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Apr 15 13:50:06 volumio kernel: usb 3-1: Product: USB2.0 HUB Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 13:50:06 volumio volumio[2924]: info: Received Get System Info Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 13:50:06 volumio volumio[2924]: info: Discovery: Getting this device information Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::volumioGetState Apr 15 13:50:06 volumio volumio[2924]: info: CorePlayQueue::getTrack 0 Apr 15 13:50:06 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 13:50:06 volumio kernel: hub 3-1:1.0: USB hub found Apr 15 13:50:06 volumio kernel: hub 3-1:1.0: 4 ports detected Apr 15 13:50:06 volumio kernel: usb usb3-port2: over-current change #77 Apr 15 13:50:06 volumio kernel: usb 3-2: USB disconnect, device number 83 Apr 15 13:50:07 volumio kernel: usb 3-2: new full-speed USB device number 85 using xhci-hcd Apr 15 13:50:07 volumio kernel: usb 3-2: New USB device found, idVendor=1a86, idProduct=e5e3, bcdDevice= 0.00 Apr 15 13:50:07 volumio kernel: usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 15 13:50:07 volumio kernel: usb 3-2: Product: USB2IIC_CTP_CONTROL Apr 15 13:50:07 volumio kernel: usb 3-2: Manufacturer: wch.cn Apr 15 13:50:07 volumio kernel: input: wch.cn USB2IIC_CTP_CONTROL as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-2/3-2:1.0/0003:1A86:E5E3.0024/input/input41 Apr 15 13:50:07 volumio kernel: hid-multitouch 0003:1A86:E5E3.0024: input,hidraw0: USB HID v1.00 Device [wch.cn USB2IIC_CTP_CONTROL] on usb-xhci-hcd.1-2/input0 Apr 15 13:50:07 volumio volumio5-onboarding[3922]: time=2026-04-15T13:50:07.468+09:00 level=INFO msg="service successfully established" component=discovery/localnet Apr 15 13:50:08 volumio volumio[2924]: info: CoreCommandRouter::executeOnPlugin: personal_radio , handleBrowseUri Apr 15 13:50:08 volumio volumio[2924]: info: Preload queue cleared Apr 15 13:50:08 volumio volumio[2924]: info: Preloading song: webmbc/0 Apr 15 13:50:08 volumio volumio[2924]: info: Preloading song: webmbc/1 Apr 15 13:50:08 volumio volumio[2924]: info: Preloading song: webmbc/2 Apr 15 13:50:08 volumio volumio[2924]: info: Exploding uri webmbc/0 in service personal_radio Apr 15 13:50:08 volumio volumio[2924]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 13:50:08 volumio volumio[2924]: TypeError: Cannot read properties of null (reading 'startsWith') Apr 15 13:50:08 volumio volumio[2924]: at /data/plugins/music_service/personal_radio/index.js:675:41 Apr 15 13:50:08 volumio volumio[2924]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Apr 15 13:50:08 volumio volumio[2924]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 13:50:09 volumio sudo[4225]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-15 13:49' Apr 15 13:50:09 volumio sudo[4225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f8b25437696d030ba01136ff33a129a42b97a4aa" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Feb 10 17:57:40 UTC 2026" VOLUMIO_VERSION="4.097" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67b01b7f4046986651bf7f5bfadaefdf"