Jun 01 14:41:00 volumio-rpi-bookworm systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 01 14:41:05 volumio-rpi-bookworm volumio[773]: info: BOOT COMPLETED Jun 01 14:41:18 volumio-rpi-bookworm systemd[1]: systemd-hostnamed.service: Deactivated successfully. Jun 01 14:41:24 volumio-rpi-bookworm kernel: usb 1-1.3: reset full-speed USB device number 4 using dwc_otg Jun 01 14:41:24 volumio-rpi-bookworm kernel: usb 1-1.3: reset full-speed USB device number 4 using dwc_otg Jun 01 14:41:28 volumio-rpi-bookworm kernel: NYET/NAK/ACK/other in non-error case, 0x00000002 Jun 01 14:41:28 volumio-rpi-bookworm kernel: NYET/NAK/ACK/other in non-error case, 0x00000002 Jun 01 14:41:28 volumio-rpi-bookworm kernel: NYET/NAK/ACK/other in non-error case, 0x00000002 Jun 01 14:41:28 volumio-rpi-bookworm kernel: usb usb1-port1: disabled by hub (EMI?), re-enabling... Jun 01 14:41:28 volumio-rpi-bookworm kernel: usb 1-1: USB disconnect, device number 2 Jun 01 14:41:28 volumio-rpi-bookworm avahi-daemon[491]: Interface eth0.IPv4 no longer relevant for mDNS. Jun 01 14:41:28 volumio-rpi-bookworm avahi-daemon[491]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.10. Jun 01 14:41:28 volumio-rpi-bookworm dhcpcd[640]: eth0: carrier lost Jun 01 14:41:28 volumio-rpi-bookworm kernel: usb 1-1.1: USB disconnect, device number 3 Jun 01 14:41:28 volumio-rpi-bookworm kernel: Jun 01 14:41:28 volumio-rpi-bookworm kernel: WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to complete on 2 Jun 01 14:41:28 volumio-rpi-bookworm kernel: smsc95xx 1-1.1:1.0 eth0: unregister 'smsc95xx' usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet Jun 01 14:41:28 volumio-rpi-bookworm kernel: smsc95xx 1-1.1:1.0 eth0: Link is Down Jun 01 14:41:28 volumio-rpi-bookworm kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Jun 01 14:41:28 volumio-rpi-bookworm dhcpcd[509]: eth0: carrier lost Jun 01 14:41:28 volumio-rpi-bookworm avahi-daemon[491]: Withdrawing address record for 192.168.1.10 on eth0. Jun 01 14:41:28 volumio-rpi-bookworm volumio[773]: info: Discovery: A device disappeared from network Jun 01 14:41:28 volumio-rpi-bookworm volumio[773]: info: Discovery: Device volumio-x86 disappeared from network Jun 01 14:41:28 volumio-rpi-bookworm kernel: usb 1-1.3: USB disconnect, device number 4 Jun 01 14:41:28 volumio-rpi-bookworm systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jun 01 14:41:28 volumio-rpi-bookworm systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jun 01 14:41:28 volumio-rpi-bookworm systemd[1]: welcome.service: Deactivated successfully. Jun 01 14:41:28 volumio-rpi-bookworm systemd[1]: Stopped welcome.service - Show a welcome message on console. Jun 01 14:41:28 volumio-rpi-bookworm systemd[1]: Stopping welcome.service - Show a welcome message on console... Jun 01 14:41:28 volumio-rpi-bookworm dhcpcd[509]: eth0: deleting route to 192.168.1.0/24 Jun 01 14:41:28 volumio-rpi-bookworm dhcpcd[509]: eth0: deleting default route via 192.168.1.1 Jun 01 14:41:28 volumio-rpi-bookworm volumio[773]: info: Discovery: Disconnected from remote: 192.168.1.4 Jun 01 14:41:28 volumio-rpi-bookworm volumio[773]: info: MRS: Cleaning up device: 59b64e30-e504-499a-95ab-c911b4014a50 Jun 01 14:41:28 volumio-rpi-bookworm dhcpcd[640]: eth0: deleting route to 192.168.1.0/24 Jun 01 14:41:28 volumio-rpi-bookworm dhcpcd[640]: eth0: deleting default route via 192.168.1.1 Jun 01 14:41:28 volumio-rpi-bookworm systemd[1]: Starting welcome.service - Show a welcome message on console... Jun 01 14:41:28 volumio-rpi-bookworm volumio[773]: info: Removing audio output: Jun 01 14:41:28 volumio-rpi-bookworm dhcpcd[509]: eth0: removing interface Jun 01 14:41:28 volumio-rpi-bookworm welcome[1708]: Resolved ip:[0] Jun 01 14:41:28 volumio-rpi-bookworm systemd[1]: Finished welcome.service - Show a welcome message on console. Jun 01 14:41:28 volumio-rpi-bookworm systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jun 01 14:41:28 volumio-rpi-bookworm kernel: Indeed it is in host mode hprt0 = 00001501 Jun 01 14:41:28 volumio-rpi-bookworm volumio[773]: info: Discovery: A device disappeared from network Jun 01 14:41:28 volumio-rpi-bookworm volumio[773]: info: Discovery: Device volumio-rpi-bookworm disappeared from network Jun 01 14:41:28 volumio-rpi-bookworm kernel: usb 1-1: new high-speed USB device number 5 using dwc_otg Jun 01 14:41:28 volumio-rpi-bookworm kernel: Indeed it is in host mode hprt0 = 00001101 Jun 01 14:41:28 volumio-rpi-bookworm ifplugd(eth0)[715]: Link beat lost. Jun 01 14:41:29 volumio-rpi-bookworm kernel: usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00 Jun 01 14:41:29 volumio-rpi-bookworm kernel: usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Jun 01 14:41:29 volumio-rpi-bookworm kernel: hub 1-1:1.0: USB hub found Jun 01 14:41:29 volumio-rpi-bookworm kernel: hub 1-1:1.0: 5 ports detected Jun 01 14:41:29 volumio-rpi-bookworm dhcpcd[640]: eth0: removing interface Jun 01 14:41:29 volumio-rpi-bookworm systemd[1]: Stopping ifup@eth0.service - ifup for eth0... Jun 01 14:41:29 volumio-rpi-bookworm ifdown[1782]: dhcpcd not running Jun 01 14:41:29 volumio-rpi-bookworm dhcpcd[1782]: dhcpcd not running Jun 01 14:41:29 volumio-rpi-bookworm kernel: usb 1-1.1: new high-speed USB device number 6 using dwc_otg Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: IO: Deleting interface #3 eth0, 192.168.1.10#123, interface stats: received=118, sent=121, dropped=1, active_time=118 secs Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 212.6.50.243 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 217.61.62.224 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 95.242.98.72 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 93.44.243.48 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 93.94.88.51 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 85.199.214.99 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 162.159.200.123 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 212.45.144.206 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 95.110.135.141 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 195.32.70.195 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 93.94.88.50 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 89.46.74.148 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 129.152.16.145 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ntpd[699]: PROTO: 162.159.200.1 unlink local addr 192.168.1.10 -> Jun 01 14:41:29 volumio-rpi-bookworm ifdown[1784]: Cannot find device "eth0" Jun 01 14:41:29 volumio-rpi-bookworm kernel: usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00 Jun 01 14:41:29 volumio-rpi-bookworm kernel: usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Jun 01 14:41:29 volumio-rpi-bookworm kernel: smsc95xx v2.0.0 Jun 01 14:41:29 volumio-rpi-bookworm systemd[1]: ifup@eth0.service: Deactivated successfully. Jun 01 14:41:29 volumio-rpi-bookworm systemd[1]: Stopped ifup@eth0.service - ifup for eth0. Jun 01 14:41:29 volumio-rpi-bookworm systemd[1]: ifup@eth0.service: Consumed 1.290s CPU time. Jun 01 14:41:29 volumio-rpi-bookworm kernel: SMSC LAN8700 usb-001:006:01: attached PHY driver (mii_bus:phy_addr=usb-001:006:01, irq=199) Jun 01 14:41:29 volumio-rpi-bookworm kernel: smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:27:70:54 Jun 01 14:41:29 volumio-rpi-bookworm (udev-worker)[1725]: Network interface NamePolicy= disabled on kernel command line. Jun 01 14:41:29 volumio-rpi-bookworm systemd[1]: Expecting device sys-subsystem-net-devices-eth0.device - /sys/subsystem/net/devices/eth0... Jun 01 14:41:29 volumio-rpi-bookworm systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 01 14:41:30 volumio-rpi-bookworm dbus-daemon[501]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.38' (uid=0 pid=1810 comm="timedatectl show --property=NTPSynchronized --valu") Jun 01 14:41:30 volumio-rpi-bookworm systemd[1]: Found device sys-subsystem-net-devices-eth0.device - SMSC9512/9514 Fast Ethernet Adapter. Jun 01 14:41:30 volumio-rpi-bookworm kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Jun 01 14:41:30 volumio-rpi-bookworm kernel: smsc95xx 1-1.1:1.0 eth0: Link is Down Jun 01 14:41:30 volumio-rpi-bookworm dhcpcd[640]: eth0: waiting for carrier Jun 01 14:41:30 volumio-rpi-bookworm systemd[1]: Started ifup@eth0.service - ifup for eth0. Jun 01 14:41:30 volumio-rpi-bookworm systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 01 14:41:30 volumio-rpi-bookworm kernel: usb 1-1.3: new full-speed USB device number 7 using dwc_otg Jun 01 14:41:30 volumio-rpi-bookworm sh[1829]: command failed: No such device (-19) Jun 01 14:41:30 volumio-rpi-bookworm sh[1839]: sending commands to dhcpcd process Jun 01 14:41:30 volumio-rpi-bookworm dhcpcd[640]: control command: dhcpcd eth0 Jun 01 14:41:30 volumio-rpi-bookworm dhcpcd[640]: control_free: No such file or directory Jun 01 14:41:30 volumio-rpi-bookworm kernel: usb 1-1.3: New USB device found, idVendor=170d, idProduct=0506, bcdDevice= 1.00 Jun 01 14:41:30 volumio-rpi-bookworm kernel: usb 1-1.3: New USB device strings: Mfr=2, Product=3, SerialNumber=0 Jun 01 14:41:30 volumio-rpi-bookworm kernel: usb 1-1.3: Product: BT Reference Jun 01 14:41:30 volumio-rpi-bookworm kernel: usb 1-1.3: Manufacturer: Avnera Jun 01 14:41:30 volumio-rpi-bookworm kernel: input: Avnera BT Reference Consumer Control as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/0003:170D:0506.0002/input/input1 Jun 01 14:41:30 volumio-rpi-bookworm kernel: hid-generic 0003:170D:0506.0002: input,hiddev96,hidraw0: USB HID v1.11 Device [Avnera BT Reference] on usb-3f980000.usb-1.3/input0 Jun 01 14:41:30 volumio-rpi-bookworm kernel: usb 1-1.3: reset full-speed USB device number 7 using dwc_otg Jun 01 14:41:31 volumio-rpi-bookworm sh[1866]: eth0=eth0 Jun 01 14:41:31 volumio-rpi-bookworm dbus-daemon[501]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 01 14:41:31 volumio-rpi-bookworm systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 01 14:41:31 volumio-rpi-bookworm setdatetime-helper.sh[1808]: Time is not synchronized. Attempting to sync... Jun 01 14:41:31 volumio-rpi-bookworm ifplugd(eth0)[715]: Link beat detected. Jun 01 14:41:31 volumio-rpi-bookworm dhcpcd[640]: eth0: carrier acquired Jun 01 14:41:31 volumio-rpi-bookworm kernel: smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off Jun 01 14:41:31 volumio-rpi-bookworm dhcpcd[640]: eth0: IAID eb:27:70:54 Jun 01 14:41:31 volumio-rpi-bookworm dhcpcd[640]: eth0: adding address fe80::4532:b810:8ef9:616b Jun 01 14:41:31 volumio-rpi-bookworm dhcpcd[640]: ipv6_addaddr1: Permission denied Jun 01 14:41:31 volumio-rpi-bookworm setdatetime-helper.sh[1808]: Sync attempt failed. Jun 01 14:41:31 volumio-rpi-bookworm systemd[1]: setdatetime-helper.timer.service: Main process exited, code=exited, status=1/FAILURE Jun 01 14:41:31 volumio-rpi-bookworm systemd[1]: setdatetime-helper.timer.service: Failed with result 'exit-code'. Jun 01 14:41:31 volumio-rpi-bookworm systemd[1]: Failed to start setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 01 14:41:31 volumio-rpi-bookworm kernel: usb 1-1.3: device descriptor read/64, error -32 Jun 01 14:41:31 volumio-rpi-bookworm dhcpcd[640]: eth0: soliciting an IPv6 router Jun 01 14:41:31 volumio-rpi-bookworm (udev-worker)[1692]: event0: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jun 01 14:41:32 volumio-rpi-bookworm dhcpcd[640]: eth0: soliciting a DHCP lease Jun 01 14:41:35 volumio-rpi-bookworm dhcpcd[640]: eth0: offered 192.168.1.10 from 192.168.1.1 Jun 01 14:41:35 volumio-rpi-bookworm dhcpcd[640]: eth0: probing address 192.168.1.10/24 Jun 01 14:41:37 volumio-rpi-bookworm volumio[773]: info: Volumio Network Manager: Network status updated: 0 Jun 01 14:41:41 volumio-rpi-bookworm dhcpcd[640]: eth0: leased 192.168.1.10 for 21600 seconds Jun 01 14:41:41 volumio-rpi-bookworm avahi-daemon[491]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.10. Jun 01 14:41:41 volumio-rpi-bookworm avahi-daemon[491]: New relevant interface eth0.IPv4 for mDNS. Jun 01 14:41:41 volumio-rpi-bookworm avahi-daemon[491]: Registering new address record for 192.168.1.10 on eth0.IPv4. Jun 01 14:41:41 volumio-rpi-bookworm dhcpcd[640]: eth0: adding route to 192.168.1.0/24 Jun 01 14:41:41 volumio-rpi-bookworm dhcpcd[640]: eth0: adding default route via 192.168.1.1 Jun 01 14:41:41 volumio-rpi-bookworm systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jun 01 14:41:41 volumio-rpi-bookworm systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jun 01 14:41:41 volumio-rpi-bookworm systemd[1]: welcome.service: Deactivated successfully. Jun 01 14:41:41 volumio-rpi-bookworm systemd[1]: Stopped welcome.service - Show a welcome message on console. Jun 01 14:41:41 volumio-rpi-bookworm systemd[1]: Stopping welcome.service - Show a welcome message on console... Jun 01 14:41:41 volumio-rpi-bookworm systemd[1]: Starting welcome.service - Show a welcome message on console... Jun 01 14:41:41 volumio-rpi-bookworm welcome[1910]: Resolved ip:[1] 192.168.1.10 Jun 01 14:41:41 volumio-rpi-bookworm systemd[1]: Finished welcome.service - Show a welcome message on console. Jun 01 14:41:41 volumio-rpi-bookworm systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jun 01 14:41:41 volumio-rpi-bookworm volumio[773]: info: Discovery: adding 59b64e30-e504-499a-95ab-c911b4014a50 Jun 01 14:41:41 volumio-rpi-bookworm volumio[773]: info: Discovery: Found device Volumio-x86 Jun 01 14:41:41 volumio-rpi-bookworm volumio[773]: info: Discovery: Connecting to remote: 192.168.1.4 Jun 01 14:41:41 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing audio output on request Jun 01 14:41:41 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:41:41 volumio-rpi-bookworm volumio[773]: info: Discovery: Connected to remote: 192.168.1.4 Jun 01 14:41:42 volumio-rpi-bookworm volumio[773]: info: Discovery: adding ec436e15-7b44-412c-a3de-3a52b8bac152 Jun 01 14:41:42 volumio-rpi-bookworm volumio[773]: info: Discovery: Found device volumio-rpi-bookworm Jun 01 14:41:42 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:41:42 volumio-rpi-bookworm ntpd[699]: IO: Listen normally on 4 eth0 192.168.1.10:123 Jun 01 14:41:42 volumio-rpi-bookworm ntpd[699]: IO: new interface(s) found: waking up resolver Jun 01 14:41:47 volumio-rpi-bookworm volumio[773]: info: Volumio Network Manager: Network status updated: 1 Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetQueue Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::getQueue Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getQueue Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: Preload queue cleared Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::ClearQueue Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::stop Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::serviceStop Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: Received STOP, but no service to execute it Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::clearPlayQueue Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::saveQueue Jun 01 14:41:48 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushQueue Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::addQueueItems Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::addQueueItems Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: Preload queue cleared Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: Adding Item to queue: http://mscp3.live-streams.nl:8250/class-flac.flac Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushQueue Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::saveQueue Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::updateTrackBlock Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrackBlock Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPlay Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: verbose: UNSET VOLATILE: Service: undefined Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: ------------------------------------ BT MESSAGE: [FUNC] detachBluetooth Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::play index 0 Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: ------------------------------------ BT MESSAGE: Bluetooth audio output disabled. Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::stop Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::resetVolumioState Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::getcurrentVolume Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioRetrievevolume Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::play index undefined Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioStop Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::stop Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::startPlaybackTimer Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetVisibleSources Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: [1748781709322] ControllerWebradio::clearAddPlayTrack Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand stop Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand stop took 36 milliseconds Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand clear Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: ---------------------------- MPD announces system playlist update Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: Ignoring MPD Status Update Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand clear took 59 milliseconds Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand load "http://mscp3.live-streams.nl:8250/class-flac.flac" Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: error: updateQueue error: null Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: ------------------------------ 55ms Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: VolumeController:: Volume=86 Mute =false Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::updateTrackBlock Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrackBlock Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioRetrievevolume Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: VolumeController:: Volume=86 Mute =false Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 01 14:41:49 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:41:50 volumio-rpi-bookworm mpd[1494]: exception: Failed to read FLAC metadata: FLAC__METADATA_CHAIN_STATUS_INVALID_CALLBACKS Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand add "http://mscp3.live-streams.nl:8250/class-flac.flac" Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: ---------------------------- MPD announces system playlist update Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: Ignoring MPD Status Update Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand add "http://mscp3.live-streams.nl:8250/class-flac.flac" took 6 milliseconds Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand play Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: ------------------------------ 34ms Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand play took 42 milliseconds Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: ---------------------------- MPD announces state update: player Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: ControllerMpd::getState Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand status Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: ---------------------------- MPD announces state update: player Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: ControllerMpd::getState Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand status Jun 01 14:41:50 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand status took 19 milliseconds Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::parseState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand status took 33 milliseconds Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand playlistinfo took 14 milliseconds Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::parseState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::parseTrackInfo Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: ControllerMpd::pushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::servicePushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"class-flac.flac","artist":null,"album":null,"uri":"http://mscp3.live-streams.nl:8250/class-flac.flac","trackType":"flac"} Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: CURRENT POSITION 0 Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::syncState stateService play Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::syncState currentStatus stop Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: ------------------------------ 121ms Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: ---------------------------- MPD announces system playlist update Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: Ignoring MPD Status Update Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: ---------------------------- MPD announces state update: player Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand playlistinfo took 65 milliseconds Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: ControllerMpd::getState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand status Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::parseTrackInfo Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: ControllerMpd::pushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::servicePushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"class-flac.flac","artist":null,"album":null,"uri":"http://mscp3.live-streams.nl:8250/class-flac.flac","trackType":"flac"} Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: CURRENT POSITION 0 Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::syncState stateService play Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::syncState currentStatus play Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: Received an update from plugin. extracting info from payload Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: ------------------------------ 711ms Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: ------------------------------ 613ms Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand status took 587 milliseconds Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::parseState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand playlistinfo took 220 milliseconds Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::parseTrackInfo Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: ControllerMpd::pushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::servicePushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: STATE SERVICE {"status":"play","position":0,"seek":206,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"class-flac.flac","artist":"Naim Classical","album":null,"uri":"http://mscp3.live-streams.nl:8250/class-flac.flac","trackType":"flac"} Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: verbose: CURRENT POSITION 0 Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::syncState stateService play Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::syncState currentStatus play Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: Received an update from plugin. extracting info from payload Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:41:51 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:41:52 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:41:52 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:41:52 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:41:52 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:41:52 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:41:52 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:41:52 volumio-rpi-bookworm volumio[773]: info: ------------------------------ 1140ms Jun 01 14:41:56 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:41:57 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: Executing endpoint metavolumio Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: Executing endpoint metavolumio Jun 01 14:41:58 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 01 14:42:01 volumio-rpi-bookworm systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: Preparing to save Alsa Options, stopping services first Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioStop Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::stop Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::stPlaybackTimer Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::updateTrackBlock Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrackBlock Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::serviceStop Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::serviceStop Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: [1748781723619] ControllerWebradio::stop Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand stop Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: Saving Audio Output to: {"output_device":{"value":"1","label":"Headphones"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 01 14:42:03 volumio-rpi-bookworm kernel: usb 1-1.3: USB disconnect, device number 7 Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: Found match in Cards Database: setting mixer PCM for card Headphones Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: QobuzConnect: setDeactiveState invoked Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:03 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:03 volumio-rpi-bookworm vtcs[1578]: [2025-06-01 14:42:03.977] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Jun 01 14:42:04 volumio-rpi-bookworm vtcs[1578]: [2025-06-01 14:42:04.001] [tisoc] [error] [SpkconServer.cpp:380] recv error. client fd=8 errorno=104 error=Connection reset by peer Jun 01 14:42:04 volumio-rpi-bookworm vtcs[1578]: [2025-06-01 14:42:04.001] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Jun 01 14:42:04 volumio-rpi-bookworm sudo[1981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 01 14:42:04 volumio-rpi-bookworm sudo[1981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:04 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jun 01 14:42:04 volumio-rpi-bookworm volumio[773]: info: Updating Volume Controller Parameters: Device: 1 Name: Headphones Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jun 01 14:42:04 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jun 01 14:42:04 volumio-rpi-bookworm volumio[773]: info: Disabling external Volume Control Jun 01 14:42:04 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 01 14:42:04 volumio-rpi-bookworm systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Jun 01 14:42:04 volumio-rpi-bookworm systemd[1]: vtcs.service: Killing process 1590 (vtcs) with signal SIGKILL. Jun 01 14:42:04 volumio-rpi-bookworm systemd[1]: vtcs.service: Deactivated successfully. Jun 01 14:42:04 volumio-rpi-bookworm systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Jun 01 14:42:04 volumio-rpi-bookworm sudo[1981]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:04 volumio-rpi-bookworm volumio[773]: info: Preparing to generate the ALSA configuration file Jun 01 14:42:04 volumio-rpi-bookworm mpd[1494]: player: played "http://mscp3.live-streams.nl:8250/class-flac.flac" Jun 01 14:42:04 volumio-rpi-bookworm sudo[1989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 01 14:42:04 volumio-rpi-bookworm sudo[1989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:05 volumio-rpi-bookworm sudo[1996]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 01 14:42:05 volumio-rpi-bookworm sudo[1996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:05 volumio-rpi-bookworm sudo[1989]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:05 volumio-rpi-bookworm sudo[1996]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: ---------------------------- MPD announces state update: player Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand stop took 1641 milliseconds Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: ControllerMpd::getState Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand status Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: Reading ALSA contributions from plugins. Jun 01 14:42:05 volumio-rpi-bookworm sudo[1999]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand status took 125 milliseconds Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::parseState Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 01 14:42:05 volumio-rpi-bookworm sudo[1999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: sendMpdCommand playlistinfo took 28 milliseconds Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::parseTrackInfo Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: ControllerMpd::pushState Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::servicePushState Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:42:05 volumio-rpi-bookworm systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Jun 01 14:42:05 volumio-rpi-bookworm qobuz-connect[1523]: 20250601 14:42:05.577 [1523.1523] INFO SampleApp: Stopping Local configuration server Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: ------------------------------ 449ms Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 14:42:05 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 01 14:42:06 volumio-rpi-bookworm qobuz-connect[1523]: 20250601 14:42:06.072 [1523.1523] INFO SampleApp: shat down connection on UNIX socket Jun 01 14:42:06 volumio-rpi-bookworm systemd[1]: qobuz-connect.service: Deactivated successfully. Jun 01 14:42:06 volumio-rpi-bookworm systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 01 14:42:06 volumio-rpi-bookworm systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Jun 01 14:42:06 volumio-rpi-bookworm sudo[1999]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: VolumeController:: Volume=86 Mute =false Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: QobuzConnect: setDeactiveState invoked Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: Executing endpoint qc_getconfig Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 01 14:42:06 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:06.550 [2008.2008] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 01 14:42:06 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:06.563 [2008.2008] INFO VolumeManager: [0x13dc358]: Setting new playback volume: 75 Jun 01 14:42:06 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:06.563 [2008.2008] INFO VolumeManager: [0x13dc358]: Setting new mute state: 0 Jun 01 14:42:06 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:06.563 [2008.2008] INFO QobuzConnect: [0x13dcd28]: Client initialized! Jun 01 14:42:06 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:06.563 [2008.2008] INFO SampleApp: Starting Avahi advertising, name: volumio-rpi-bookworm, service name: _qobuz-connect._tcp Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 01 14:42:06 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:06.599 [2008.2008] INFO LocalConfigManager: [0x13dbc38]: Starting Local Configuration server Jun 01 14:42:06 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:06.599 [2008.2008] INFO SampleApp: Starting Local configuration server Jun 01 14:42:06 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:06.601 [2008.2008] INFO SampleApp: Connected to UNIX socket client 0x13c6818 Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: Asound.conf file unchanged, so no further update is needed Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: Output device has changed, restarting MPD Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: Output device has changed, restarting Shairport Sync Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 14:42:06 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:06.700 [2008.2008] INFO SampleApp: Playback volume changed: 75 Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 01 14:42:06 volumio-rpi-bookworm sudo[2012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: QobuzConnect: setDeactiveState invoked Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 01 14:42:06 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:06 volumio-rpi-bookworm sudo[2012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:06 volumio-rpi-bookworm sudo[2012]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:06 volumio-rpi-bookworm sudo[2016]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 01 14:42:06 volumio-rpi-bookworm sudo[2016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:07 volumio-rpi-bookworm systemd[1]: Stopping mpd.service - Music Player Daemon... Jun 01 14:42:07 volumio-rpi-bookworm systemd[1]: mpd.service: Deactivated successfully. Jun 01 14:42:07 volumio-rpi-bookworm systemd[1]: Stopped mpd.service - Music Player Daemon. Jun 01 14:42:07 volumio-rpi-bookworm systemd[1]: mpd.service: Consumed 6.185s CPU time. Jun 01 14:42:07 volumio-rpi-bookworm systemd[1]: mpd.socket: Deactivated successfully. Jun 01 14:42:07 volumio-rpi-bookworm sudo[2025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 01 14:42:07 volumio-rpi-bookworm sudo[2025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:07 volumio-rpi-bookworm systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jun 01 14:42:07 volumio-rpi-bookworm systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jun 01 14:42:07 volumio-rpi-bookworm sudo[2026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jun 01 14:42:07 volumio-rpi-bookworm systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jun 01 14:42:07 volumio-rpi-bookworm sudo[2026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:07 volumio-rpi-bookworm systemd[1]: Starting mpd.service - Music Player Daemon... Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:07 volumio-rpi-bookworm sudo[2034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 01 14:42:07 volumio-rpi-bookworm sudo[2034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:07 volumio-rpi-bookworm sudo[2025]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: MPD Permissions set Jun 01 14:42:07 volumio-rpi-bookworm sudo[2034]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: TidalConnect service stoped! Jun 01 14:42:07 volumio-rpi-bookworm sudo[2026]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:07 volumio-rpi-bookworm sudo[2035]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 01 14:42:07 volumio-rpi-bookworm sudo[2039]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 01 14:42:07 volumio-rpi-bookworm sudo[2035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 01 14:42:07 volumio-rpi-bookworm sudo[2039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:07 volumio-rpi-bookworm sudo[2035]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:07 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 14:42:07 volumio-rpi-bookworm systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Jun 01 14:42:08 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:07.997 [2008.2008] INFO SampleApp: Stopping Local configuration server Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: TidalConnect service stoped! Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::getcurrentVolume Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioRetrievevolume Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: Starting Shairport Sync Jun 01 14:42:08 volumio-rpi-bookworm qobuz-connect[2008]: 20250601 14:42:08.608 [2008.2008] INFO SampleApp: shat down connection on UNIX socket Jun 01 14:42:08 volumio-rpi-bookworm systemd[1]: qobuz-connect.service: Deactivated successfully. Jun 01 14:42:08 volumio-rpi-bookworm systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Jun 01 14:42:08 volumio-rpi-bookworm systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPlay Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::play index undefined Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::startPlaybackTimer Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetVisibleSources Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 01 14:42:08 volumio-rpi-bookworm sudo[2039]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: [1748781728784] ControllerWebradio::clearAddPlayTrack Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: verbose: ControllerMpd::sendMpdCommand stop Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: QobuzConnect: setDeactiveState invoked Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:08 volumio-rpi-bookworm sudo[2069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 01 14:42:08 volumio-rpi-bookworm sudo[2069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:08 volumio-rpi-bookworm volumio[773]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: Executing endpoint qc_getconfig Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 01 14:42:09 volumio-rpi-bookworm systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jun 01 14:42:09 volumio-rpi-bookworm systemd[1]: shairport-sync.service: Deactivated successfully. Jun 01 14:42:09 volumio-rpi-bookworm systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 01 14:42:09 volumio-rpi-bookworm systemd[1]: shairport-sync.service: Consumed 2.062s CPU time. Jun 01 14:42:09 volumio-rpi-bookworm qobuz-connect[2070]: 20250601 14:42:09.195 [2070.2070] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 01 14:42:09 volumio-rpi-bookworm systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 01 14:42:09 volumio-rpi-bookworm qobuz-connect[2070]: 20250601 14:42:09.214 [2070.2070] INFO VolumeManager: [0xca8358]: Setting new playback volume: 75 Jun 01 14:42:09 volumio-rpi-bookworm qobuz-connect[2070]: 20250601 14:42:09.214 [2070.2070] INFO VolumeManager: [0xca8358]: Setting new mute state: 0 Jun 01 14:42:09 volumio-rpi-bookworm qobuz-connect[2070]: 20250601 14:42:09.215 [2070.2070] INFO QobuzConnect: [0xca8d28]: Client initialized! Jun 01 14:42:09 volumio-rpi-bookworm qobuz-connect[2070]: 20250601 14:42:09.215 [2070.2070] INFO SampleApp: Starting Avahi advertising, name: volumio-rpi-bookworm, service name: _qobuz-connect._tcp Jun 01 14:42:09 volumio-rpi-bookworm qobuz-connect[2070]: 20250601 14:42:09.272 [2070.2070] INFO LocalConfigManager: [0xca7c38]: Starting Local Configuration server Jun 01 14:42:09 volumio-rpi-bookworm qobuz-connect[2070]: 20250601 14:42:09.272 [2070.2070] INFO SampleApp: Starting Local configuration server Jun 01 14:42:09 volumio-rpi-bookworm qobuz-connect[2070]: 20250601 14:42:09.273 [2070.2070] INFO SampleApp: Connected to UNIX socket client 0xc92818 Jun 01 14:42:09 volumio-rpi-bookworm sudo[2069]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 01 14:42:09 volumio-rpi-bookworm qobuz-connect[2070]: 20250601 14:42:09.345 [2070.2070] INFO SampleApp: Playback volume changed: 75 Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: VolumeController:: Volume=86 Mute =false Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::updateTrackBlock Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrackBlock Jun 01 14:42:09 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioRetrievevolume Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: Shairport-Sync Started Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: Executing endpoint metavolumio Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 01 14:42:10 volumio-rpi-bookworm sudo[2097]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 01 14:42:10 volumio-rpi-bookworm sudo[2097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: TidalConnect service stoped! Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: VolumeController:: Volume=86 Mute =false Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 01 14:42:10 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:42:11 volumio-rpi-bookworm systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Jun 01 14:42:11 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:11 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:11 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:42:11 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:42:11 volumio-rpi-bookworm sudo[2097]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:11 volumio-rpi-bookworm volumio[773]: info: TidalConnect service stoped! Jun 01 14:42:11 volumio-rpi-bookworm volumio[773]: info: Executing endpoint tc_getconfig Jun 01 14:42:11 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Jun 01 14:42:11 volumio-rpi-bookworm vtcs[2100]: STARTING TidalConnect services, version: 1.5.0.45 Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jun 01 14:42:12 volumio-rpi-bookworm vtcs[2100]: STARTED TidalConnect services. Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: Executing endpoint tc_connect Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: Connecting to TidalConnect Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::servicePushState Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::servicePushState Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CoreStateMachine::pushState Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioPushState Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::volumioGetState Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output update for this device Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: MRS: Pushing multiroomSync output Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: CorePlayQueue::getTrack 0 Jun 01 14:42:12 volumio-rpi-bookworm volumio[773]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Jun 01 14:42:12 volumio-rpi-bookworm sudo[2121]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jun 01 14:42:12 volumio-rpi-bookworm sudo[2121]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:12 volumio-rpi-bookworm sudo[2121]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:13 volumio-rpi-bookworm mpd[2043]: 2025-06-01T14:42:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 01 14:42:13 volumio-rpi-bookworm systemd[1]: Started mpd.service - Music Player Daemon. Jun 01 14:42:13 volumio-rpi-bookworm sudo[2016]: pam_unix(sudo:session): session closed for user root Jun 01 14:42:13 volumio-rpi-bookworm volumio[773]: error: updateQueue error: null Jun 01 14:42:14 volumio-rpi-bookworm volumio[773]: info: TidalConnect service started! Jun 01 14:42:14 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 01 14:42:14 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 01 14:42:14 volumio-rpi-bookworm volumio[773]: info: Preload queue cleared Jun 01 14:42:15 volumio-rpi-bookworm volumio[773]: info: TidalConnect service started! Jun 01 14:42:16 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 01 14:42:16 volumio-rpi-bookworm volumio[773]: info: Preload queue cleared Jun 01 14:42:17 volumio-rpi-bookworm volumio[773]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 01 14:42:18 volumio-rpi-bookworm volumio[773]: Use XMLElement.setAttribute instead Jun 01 14:42:18 volumio-rpi-bookworm volumio[773]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 01 14:42:18 volumio-rpi-bookworm volumio[773]: TypeError: children[i].attr(...).value is not a function Jun 01 14:42:18 volumio-rpi-bookworm volumio[773]: at /volumio/app/plugins/music_service/webradio/index.js:428:46 Jun 01 14:42:18 volumio-rpi-bookworm volumio[773]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jun 01 14:42:18 volumio-rpi-bookworm volumio[773]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 01 14:42:24 volumio-rpi-bookworm kernel: usb 1-1.3: new full-speed USB device number 10 using dwc_otg Jun 01 14:42:24 volumio-rpi-bookworm kernel: usb 1-1.3: New USB device found, idVendor=170d, idProduct=0506, bcdDevice= 1.00 Jun 01 14:42:24 volumio-rpi-bookworm kernel: usb 1-1.3: New USB device strings: Mfr=2, Product=3, SerialNumber=0 Jun 01 14:42:24 volumio-rpi-bookworm kernel: usb 1-1.3: Product: BT Reference Jun 01 14:42:24 volumio-rpi-bookworm kernel: usb 1-1.3: Manufacturer: Avnera Jun 01 14:42:24 volumio-rpi-bookworm kernel: input: Avnera BT Reference Consumer Control as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/0003:170D:0506.0003/input/input2 Jun 01 14:42:24 volumio-rpi-bookworm kernel: hid-generic 0003:170D:0506.0003: input,hiddev96,hidraw0: USB HID v1.11 Device [Avnera BT Reference] on usb-3f980000.usb-1.3/input0 Jun 01 14:42:24 volumio-rpi-bookworm (udev-worker)[2157]: event0: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jun 01 14:42:24 volumio-rpi-bookworm sudo[2166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-01 14:41' Jun 01 14:42:24 volumio-rpi-bookworm sudo[2166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 01 14:42:24 volumio-rpi-bookworm kernel: usb 1-1.3: reset full-speed USB device number 10 using dwc_otg 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="fd567ba9bc0dc34c0403e2d5b72a0f46467d1983" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri May 23 08:02:06 UTC 2025" VOLUMIO_VERSION="0.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="76fa67e30b28261e1dc7c3a89e610b9e"