-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Fri 2024-04-12 19:55:11 CEST. -- Apr 12 19:54:34 test fake-hwclock[215]: Fri Apr 12 17:54:34 UTC 2024 Apr 12 19:54:34 test systemd[1]: Started Restore / save the current clock. Apr 12 19:54:34 test systemd[1]: Started Load/Save Random Seed. Apr 12 19:54:34 test systemd[1]: Started Apply Kernel Variables. Apr 12 19:54:34 test systemd[1]: Started Create System Users. Apr 12 19:54:34 test systemd[1]: Starting Create Static Device Nodes in /dev... Apr 12 19:54:34 test systemd[1]: dynamicswap.service: Succeeded. Apr 12 19:54:34 test systemd[1]: Started Create Static Device Nodes in /dev. Apr 12 19:54:34 test systemd[1]: Starting udev Kernel Device Manager... Apr 12 19:54:34 test systemd[1]: Reached target Local File Systems (Pre). Apr 12 19:54:34 test systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Apr 12 19:54:34 test systemd[1]: Mounting /var/log... Apr 12 19:54:34 test systemd[1]: Mounting /var/spool/cups... Apr 12 19:54:34 test systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Apr 12 19:54:34 test systemd[1]: Mounting /tmp... Apr 12 19:54:34 test systemd[1]: Mounted /var/log. Apr 12 19:54:34 test systemd[1]: Mounted /var/spool/cups. Apr 12 19:54:34 test systemd[1]: Mounted /tmp. Apr 12 19:54:34 test systemd[1]: Mounting /var/spool/cups/tmp... Apr 12 19:54:34 test systemd[1]: Starting Flush Journal to Persistent Storage... Apr 12 19:54:34 test systemd[1]: Mounted /var/spool/cups/tmp. Apr 12 19:54:34 test systemd-udevd[237]: Network interface NamePolicy= disabled on kernel command line, ignoring. Apr 12 19:54:34 test systemd-journald[212]: Runtime journal (/run/log/journal/c1d531165394c79721acb5a765d65e88) is 7.5M, max 30.0M, 22.5M free. Apr 12 19:54:34 test systemd[1]: Started Flush Journal to Persistent Storage. Apr 12 19:54:34 test systemd[1]: Started udev Kernel Device Manager. Apr 12 19:54:34 test systemd[1]: Started udev Coldplug all Devices. Apr 12 19:54:34 test systemd[1]: Starting Show Plymouth Boot Screen... Apr 12 19:54:34 test systemd[1]: Starting Helper to synchronize boot up for ifupdown... Apr 12 19:54:34 test kernel: input: pwr_button as /devices/platform/pwr_button/input/input0 Apr 12 19:54:34 test systemd[1]: Started Helper to synchronize boot up for ifupdown. Apr 12 19:54:34 test systemd[1]: Received SIGRTMIN+20 from PID 269 (plymouthd). Apr 12 19:54:34 test systemd[1]: Started Show Plymouth Boot Screen. Apr 12 19:54:34 test systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Apr 12 19:54:34 test systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Apr 12 19:54:34 test systemd[1]: Reached target Paths. Apr 12 19:54:34 test systemd[1]: Reached target Local Encrypted Volumes. Apr 12 19:54:34 test systemd-udevd[251]: Using default interface naming scheme 'v240'. Apr 12 19:54:34 test kernel: rpi-gpiomem 107d508500.gpiomem: window base 0x107d508500 size 0x00000040 Apr 12 19:54:34 test kernel: rpi-gpiomem 107d508500.gpiomem: initialised 1 regions as /dev/gpiomem1 Apr 12 19:54:34 test kernel: rpi-gpiomem 107d517c00.gpiomem: window base 0x107d517c00 size 0x00000040 Apr 12 19:54:34 test kernel: mc: Linux media interface: v0.10 Apr 12 19:54:34 test kernel: rpi-gpiomem 107d517c00.gpiomem: initialised 1 regions as /dev/gpiomem2 Apr 12 19:54:34 test kernel: rpi-gpiomem 107d504100.gpiomem: window base 0x107d504100 size 0x00000020 Apr 12 19:54:34 test kernel: rpi-gpiomem 107d504100.gpiomem: initialised 1 regions as /dev/gpiomem3 Apr 12 19:54:34 test kernel: rpi-gpiomem 107d510700.gpiomem: window base 0x107d510700 size 0x00000020 Apr 12 19:54:34 test kernel: rpi-gpiomem 107d510700.gpiomem: initialised 1 regions as /dev/gpiomem4 Apr 12 19:54:34 test kernel: rpi-gpiomem 1f000d0000.gpiomem: window base 0x1f000d0000 size 0x00030000 Apr 12 19:54:34 test kernel: rpi-gpiomem 1f000d0000.gpiomem: initialised 1 regions as /dev/gpiomem0 Apr 12 19:54:34 test kernel: videodev: Linux video capture interface: v2.00 Apr 12 19:54:34 test kernel: brcmstb-i2c 107d508200.i2c: @200000hz registered in interrupt mode Apr 12 19:54:34 test kernel: brcmstb-i2c 107d508280.i2c: @200000hz registered in interrupt mode Apr 12 19:54:34 test kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. Apr 12 19:54:34 test kernel: rpivid 1000800000.codec: bcm2712_iommu_of_xlate: MMU 1000005100.iommu Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: bcm2712_iommu_of_xlate: MMU 1000005100.iommu Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: pispbe_probe: HW version: 0x02252700 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: pispbe_probe: BatchStatus: 0x00000000 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: pispbe_probe: Status: 0x00000000 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: Register nodes for group 0 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: input device node registered as /dev/video20 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: tdn_input device node registered as /dev/video21 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: stitch_input device node registered as /dev/video22 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: hog_output device node registered as /dev/video23 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: output0 device node registered as /dev/video24 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: output1 device node registered as /dev/video25 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: tdn_output device node registered as /dev/video26 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: stitch_output device node registered as /dev/video27 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: config device node registered as /dev/video28 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: Register nodes for group 1 Apr 12 19:54:34 test kernel: rpivid 1000800000.codec: Device registered as /dev/video19 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: input device node registered as /dev/video29 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: tdn_input device node registered as /dev/video30 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: stitch_input device node registered as /dev/video31 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: hog_output device node registered as /dev/video32 Apr 12 19:54:34 test kernel: [drm] Initialized v3d 1.0.0 20180419 for 1002000000.v3d on minor 0 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: output0 device node registered as /dev/video33 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: output1 device node registered as /dev/video34 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: tdn_output device node registered as /dev/video35 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: stitch_output device node registered as /dev/video36 Apr 12 19:54:34 test kernel: pispbe 1000880000.pisp_be: config device node registered as /dev/video37 Apr 12 19:54:34 test systemd-udevd[251]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 12 19:54:34 test systemd[1]: Found device /dev/ttyAMA10. Apr 12 19:54:34 test systemd[1]: Found device /sys/subsystem/net/devices/eth0. Apr 12 19:54:34 test kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Apr 12 19:54:34 test kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Apr 12 19:54:34 test kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Apr 12 19:54:34 test kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Apr 12 19:54:34 test kernel: Bluetooth: Core ver 2.22 Apr 12 19:54:34 test kernel: NET: Registered PF_BLUETOOTH protocol family Apr 12 19:54:34 test kernel: Bluetooth: HCI device and connection manager initialized Apr 12 19:54:34 test kernel: Bluetooth: HCI socket layer initialized Apr 12 19:54:34 test kernel: Bluetooth: L2CAP socket layer initialized Apr 12 19:54:34 test kernel: Bluetooth: SCO socket layer initialized Apr 12 19:54:34 test kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: bcm2712_iommu_of_xlate: MMU 1000005200.iommu Apr 12 19:54:34 test kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Apr 12 19:54:34 test kernel: usbcore: registered new interface driver brcmfmac Apr 12 19:54:34 test kernel: brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,5-model-b.bin failed with error -2 Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: bound 107c580000.hvs (ops vc4_hvs_ops [vc4]) Apr 12 19:54:34 test kernel: Registered IR keymap rc-cec Apr 12 19:54:34 test kernel: rc rc0: vc4-hdmi-0 as /devices/platform/soc/107c701400.hdmi/rc/rc0 Apr 12 19:54:34 test kernel: input: vc4-hdmi-0 as /devices/platform/soc/107c701400.hdmi/rc/rc0/input1 Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: bound 107c701400.hdmi (ops vc4_hdmi_ops [vc4]) Apr 12 19:54:34 test kernel: Bluetooth: HCI UART driver ver 2.3 Apr 12 19:54:34 test kernel: Bluetooth: HCI UART protocol H4 registered Apr 12 19:54:34 test kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Apr 12 19:54:34 test kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Apr 12 19:54:34 test kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Apr 12 19:54:34 test kernel: Bluetooth: HCI UART protocol Broadcom registered Apr 12 19:54:34 test kernel: Registered IR keymap rc-cec Apr 12 19:54:34 test kernel: rc rc1: vc4-hdmi-1 as /devices/platform/soc/107c706400.hdmi/rc/rc1 Apr 12 19:54:34 test kernel: input: vc4-hdmi-1 as /devices/platform/soc/107c706400.hdmi/rc/rc1/input2 Apr 12 19:54:34 test systemd-udevd[255]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: bound 107c706400.hdmi (ops vc4_hdmi_ops [vc4]) Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: bound 107c500000.mop (ops vc4_txp_ops [vc4]) Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: bound 107c501000.moplet (ops vc4_txp_ops [vc4]) Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: bound 107c410000.pixelvalve (ops vc4_crtc_ops [vc4]) Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: bound 107c411000.pixelvalve (ops vc4_crtc_ops [vc4]) Apr 12 19:54:34 test kernel: [drm] Initialized vc4 0.0.0 20140616 for axi:gpu on minor 1 Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: [drm] Cannot find any crtc or sizes Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: [drm] Cannot find any crtc or sizes Apr 12 19:54:34 test kernel: vc4-drm axi:gpu: [drm] Cannot find any crtc or sizes Apr 12 19:54:34 test kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 Apr 12 19:54:34 test systemd-udevd[275]: Using default interface naming scheme 'v240'. Apr 12 19:54:34 test systemd-udevd[275]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 12 19:54:34 test systemd-udevd[249]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 12 19:54:34 test systemd-udevd[255]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 12 19:54:34 test systemd[1]: Found device /dev/mmcblk0p1. Apr 12 19:54:35 test kernel: snd-rpi-hifiberry-dacplus soc:sound: GPIO4 for HW-MUTE selected Apr 12 19:54:35 test kernel: snd-rpi-hifiberry-dacplus soc:sound: GPIO17 for HW-RESET selected Apr 12 19:54:35 test systemd-udevd[283]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 12 19:54:35 test kernel: Bluetooth: hci0: BCM: chip id 107 Apr 12 19:54:35 test kernel: Bluetooth: hci0: BCM: features 0x2f Apr 12 19:54:35 test kernel: Bluetooth: hci0: BCM4345C0 Apr 12 19:54:35 test kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Apr 12 19:54:35 test kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Apr 12 19:54:35 test systemd[1]: Created slice system-bthelper.slice. Apr 12 19:54:35 test systemd[1]: Condition check resulted in Huge Pages File System being skipped. Apr 12 19:54:35 test systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Apr 12 19:54:35 test systemd[1]: Condition check resulted in FUSE Control File System being skipped. Apr 12 19:54:35 test systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Apr 12 19:54:35 test systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Apr 12 19:54:35 test systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Apr 12 19:54:35 test systemd[1]: Starting File System Check on /dev/mmcblk0p1... Apr 12 19:54:35 test systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 12 19:54:35 test systemd[1]: Started File System Check Daemon to report status. Apr 12 19:54:35 test systemd-fsck[545]: fsck.fat 4.1 (2017-01-24) Apr 12 19:54:35 test systemd-fsck[545]: /dev/mmcblk0p1: 367 files, 33349/46774 clusters Apr 12 19:54:35 test systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Apr 12 19:54:35 test systemd[1]: Started Load/Save RF Kill Switch Status. Apr 12 19:54:35 test systemd[1]: Started File System Check on /dev/mmcblk0p1. Apr 12 19:54:35 test systemd[1]: Mounting /boot... Apr 12 19:54:35 test systemd[1]: Mounted /boot. Apr 12 19:54:35 test systemd[1]: Reached target Local File Systems. Apr 12 19:54:35 test systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Apr 12 19:54:35 test systemd[1]: Starting Preprocess NFS configuration... Apr 12 19:54:35 test systemd[1]: Starting Raise network interfaces... Apr 12 19:54:35 test systemd[1]: Started ifup for wlan0. Apr 12 19:54:35 test systemd[1]: Started ifup for eth0. Apr 12 19:54:35 test systemd[1]: Starting Create Volatile Files and Directories... Apr 12 19:54:35 test systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Apr 12 19:54:35 test systemd[1]: Received SIGRTMIN+20 from PID 269 (plymouthd). Apr 12 19:54:35 test systemd[1]: plymouth-read-write.service: Succeeded. Apr 12 19:54:35 test systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Apr 12 19:54:35 test systemd[1]: nfs-config.service: Succeeded. Apr 12 19:54:35 test systemd[1]: Started Preprocess NFS configuration. Apr 12 19:54:35 test systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Apr 12 19:54:35 test systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Apr 12 19:54:35 test systemd[1]: Reached target NFS client services. Apr 12 19:54:35 test systemd[1]: Started Create Volatile Files and Directories. Apr 12 19:54:35 test systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Apr 12 19:54:35 test systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Apr 12 19:54:35 test systemd[1]: Starting RPC bind portmap service... Apr 12 19:54:35 test systemd[1]: Starting Update UTMP about System Boot/Shutdown... Apr 12 19:54:35 test kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 12 19:54:35 test systemd[1]: Started Update UTMP about System Boot/Shutdown. Apr 12 19:54:35 test systemd[1]: Reached target System Initialization. Apr 12 19:54:35 test systemd[1]: Listening on D-Bus System Message Bus Socket. Apr 12 19:54:35 test kernel: 8021q: 802.1Q VLAN Support v1.8 Apr 12 19:54:35 test systemd[1]: Started Daily Cleanup of Temporary Directories. Apr 12 19:54:35 test systemd[1]: Started Daily apt download activities. Apr 12 19:54:35 test systemd[1]: Started Daily apt upgrade and clean activities. Apr 12 19:54:35 test systemd[1]: Reached target Timers. Apr 12 19:54:35 test systemd[1]: Started Volumio Splash. Apr 12 19:54:35 test systemd[653]: volumiosplash.service: Failed to execute command: No such file or directory Apr 12 19:54:35 test systemd[653]: volumiosplash.service: Failed at step EXEC spawning /bin/volumiosplash.sh: No such file or directory Apr 12 19:54:35 test systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Apr 12 19:54:35 test systemd[1]: Listening on triggerhappy.socket. Apr 12 19:54:35 test systemd[1]: Reached target Sockets. Apr 12 19:54:35 test systemd[1]: Reached target Basic System. Apr 12 19:54:35 test systemd[1]: Started Manage Sound Card State (restore and store). Apr 12 19:54:35 test systemd[1]: Started UPnP Renderer front-end to MPD. Apr 12 19:54:35 test systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Apr 12 19:54:35 test alsactl[663]: alsactl 1.1.8 daemon started Apr 12 19:54:35 test systemd[1]: Starting triggerhappy global hotkey daemon... Apr 12 19:54:35 test systemd[1]: Starting Login Service... Apr 12 19:54:35 test systemd[1]: Condition check resulted in Configure Bluetooth Modems connected by UART being skipped. Apr 12 19:54:35 test systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Apr 12 19:54:35 test systemd[1]: Starting dhcpcd on all interfaces... Apr 12 19:54:35 test systemd[1]: Started Volumio Log Rotation Service. Apr 12 19:54:35 test systemd[1]: Starting Raspberry Pi bluetooth helper... Apr 12 19:54:35 test systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Apr 12 19:54:35 test systemd[1]: Started volumio-remote-updater.service. Apr 12 19:54:35 test thd[667]: Unable to parse trigger line: Apr 12 19:54:35 test thd[667]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Apr 12 19:54:35 test thd[667]: Unable to parse trigger line: Apr 12 19:54:35 test thd[667]: Found socket passed from systemd Apr 12 19:54:35 test systemd[1]: Started Volumio Iptables Module. Apr 12 19:54:35 test systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Apr 12 19:54:35 test systemd[1]: Started D-Bus System Message Bus. Apr 12 19:54:35 test systemd[1]: Starting WPA supplicant... Apr 12 19:54:35 test systemd[1]: Starting Save/Restore Sound Card State... Apr 12 19:54:35 test systemd[1]: Starting Wireless Services... Apr 12 19:54:35 test systemd[1]: Started RPC bind portmap service. Apr 12 19:54:35 test systemd[1]: Started triggerhappy global hotkey daemon. Apr 12 19:54:35 test systemd[1]: haveged.service: Main process exited, code=killed, status=11/SEGV Apr 12 19:54:35 test dhcpcd[670]: Not running dhcpcd because /etc/network/interfaces Apr 12 19:54:35 test dhcpcd[670]: defines some interfaces that will use a Apr 12 19:54:35 test dhcpcd[670]: DHCP client or static address Apr 12 19:54:35 test systemd[1]: haveged.service: Failed with result 'signal'. Apr 12 19:54:35 test systemd[1]: volumiosplash.service: Main process exited, code=exited, status=203/EXEC Apr 12 19:54:35 test systemd[1]: volumiosplash.service: Failed with result 'exit-code'. Apr 12 19:54:35 test systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Apr 12 19:54:35 test systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Apr 12 19:54:35 test systemd[1]: Failed to start dhcpcd on all interfaces. Apr 12 19:54:35 test systemd[1]: Reached target RPC Port Mapper. Apr 12 19:54:35 test systemd[1]: Reached target Remote File Systems (Pre). Apr 12 19:54:35 test systemd[1]: Reached target Remote File Systems. Apr 12 19:54:35 test systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Apr 12 19:54:35 test systemd[1]: Started Save/Restore Sound Card State. Apr 12 19:54:35 test systemd[1]: Reached target Sound Card. Apr 12 19:54:35 test sh[555]: wlan0=wlan0 Apr 12 19:54:35 test kernel: macb 1f00100000.ethernet eth0: PHY [1f00100000.ethernet-ffffffff:01] driver [Broadcom BCM54213PE] (irq=POLL) Apr 12 19:54:35 test kernel: macb 1f00100000.ethernet eth0: configuring for phy/rgmii-id link mode Apr 12 19:54:35 test kernel: pps pps0: new PPS source ptp0 Apr 12 19:54:35 test kernel: macb 1f00100000.ethernet: gem-ptp-timer ptp clock registered. Apr 12 19:54:35 test dhcpcd[602]: eth0: waiting for carrier Apr 12 19:54:35 test sh[557]: eth0: waiting for carrier Apr 12 19:54:35 test systemd-logind[669]: New seat seat0. Apr 12 19:54:35 test systemd-logind[669]: Watching system buttons on /dev/input/event0 (pwr_button) Apr 12 19:54:35 test systemd-logind[669]: Watching system buttons on /dev/input/event1 (vc4-hdmi-0) Apr 12 19:54:35 test systemd-logind[669]: Watching system buttons on /dev/input/event2 (vc4-hdmi-1) Apr 12 19:54:35 test avahi-daemon[673]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Apr 12 19:54:35 test avahi-daemon[673]: Successfully dropped root privileges. Apr 12 19:54:35 test avahi-daemon[673]: avahi-daemon 0.7 starting up. Apr 12 19:54:35 test systemd[1]: Started Login Service. Apr 12 19:54:35 test wpa_supplicant[679]: Successfully initialized wpa_supplicant Apr 12 19:54:35 test avahi-daemon[673]: Successfully called chroot(). Apr 12 19:54:35 test avahi-daemon[673]: Successfully dropped remaining capabilities. Apr 12 19:54:35 test avahi-daemon[673]: Loading service file /services/volumio.service. Apr 12 19:54:35 test avahi-daemon[673]: Network interface enumeration completed. Apr 12 19:54:35 test avahi-daemon[673]: Server startup complete. Host name is test.local. Local service cookie is 2978969929. Apr 12 19:54:35 test avahi-daemon[673]: Service "Test" (/services/volumio.service) successfully established. Apr 12 19:54:35 test systemd[1]: Started Raise network interfaces. Apr 12 19:54:35 test systemd[1]: Started WPA supplicant. Apr 12 19:54:35 test systemd[1]: Started Avahi mDNS/DNS-SD Stack. Apr 12 19:54:35 test systemd[1]: Reached target Network. Apr 12 19:54:35 test kernel: Bluetooth: hci0: BCM: features 0x2f Apr 12 19:54:35 test kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Apr 12 19:54:35 test kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Apr 12 19:54:35 test kernel: Bluetooth: hci0: BCM: Using default device address (43:45:c0:00:1f:ac) Apr 12 19:54:35 test systemd[1]: Starting Permit User Sessions... Apr 12 19:54:35 test systemd[1]: Starting Network Time Service... Apr 12 19:54:35 test systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Apr 12 19:54:35 test systemd[1]: Reached target Network is Online. Apr 12 19:54:35 test systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 12 19:54:35 test systemd[1]: Starting Samba NMB Daemon... Apr 12 19:54:35 test systemd[1]: Starting /etc/rc.local Compatibility... Apr 12 19:54:35 test systemd[1]: Starting LSB: Brings up/down network automatically... Apr 12 19:54:35 test bthelper[672]: Raspberry Pi BDADDR already set Apr 12 19:54:35 test systemd[1]: Started Permit User Sessions. Apr 12 19:54:35 test systemd[1]: Started Raspberry Pi bluetooth helper. Apr 12 19:54:35 test systemd[1]: Started /etc/rc.local Compatibility. Apr 12 19:54:35 test systemd[1]: Starting Bluetooth service... Apr 12 19:54:35 test systemd[1]: Starting Terminate Plymouth Boot Screen... Apr 12 19:54:35 test systemd[1]: Starting Hold until boot process finishes up... Apr 12 19:54:35 test systemd[1]: Received SIGRTMIN+21 from PID 269 (plymouthd). Apr 12 19:54:35 test systemd[1]: plymouth-start.service: Succeeded. Apr 12 19:54:35 test systemd[1]: plymouth-quit.service: Succeeded. Apr 12 19:54:35 test systemd[1]: Started Terminate Plymouth Boot Screen. Apr 12 19:54:35 test systemd[1]: plymouth-quit-wait.service: Succeeded. Apr 12 19:54:35 test systemd[1]: Started Hold until boot process finishes up. Apr 12 19:54:35 test systemd[1]: Started Getty on tty1. Apr 12 19:54:35 test systemd[1]: Started Serial Getty on ttyAMA10. Apr 12 19:54:35 test volumio-remote-updater[674]: Error: No active session Apr 12 19:54:35 test systemd[1]: Reached target Login Prompts. Apr 12 19:54:35 test volumio-remote-updater[674]: [2024-04-12 19:54:35] [info] asio async_connect error: system:111 (Connection refused) Apr 12 19:54:35 test volumio-remote-updater[674]: [2024-04-12 19:54:35] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 12 19:54:35 test volumio-remote-updater[674]: [2024-04-12 19:54:35] [error] handle_connect error: Underlying Transport Error Apr 12 19:54:35 test volumio[665]: Could not open config: /tmp/upmpdcli.conf Apr 12 19:54:35 test systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 12 19:54:35 test systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 12 19:54:35 test ifplugd(eth0)[799]: ifplugd 0.28 initializing. Apr 12 19:54:35 test ifplugd(eth0)[799]: Using interface eth0/2C:CF:67:26:5B:FB with driver (version: 6.1.69-v8+) Apr 12 19:54:35 test ifplugd(eth0)[799]: Using detection mode: SIOCETHTOOL Apr 12 19:54:35 test ifplugd(eth0)[799]: Initialization complete, link beat not detected. Apr 12 19:54:35 test loadcpufreq[685]: Loading cpufreq kernel modules...done (none). Apr 12 19:54:35 test systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Apr 12 19:54:35 test systemd[1]: iptables.service: Succeeded. Apr 12 19:54:35 test systemd[1]: Starting LSB: set CPUFreq kernel parameters... Apr 12 19:54:36 test ntpd[736]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 12 19:54:36 test ntpd[736]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Apr 12 19:54:36 test systemd[1]: Started Network Time Service. Apr 12 19:54:36 test ntpd[803]: proto: precision = 1.259 usec (-20) Apr 12 19:54:36 test ntpd[803]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 12 19:54:36 test ntpd[803]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-06-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 12 19:54:36 test ntpd[803]: Listen and drop on 0 v6wildcard [::]:123 Apr 12 19:54:36 test ntpd[803]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 12 19:54:36 test ntpd[803]: Listen normally on 2 lo 127.0.0.1:123 Apr 12 19:54:36 test ntpd[803]: Listening on routing socket on fd #19 for interface updates Apr 12 19:54:36 test ntpd[803]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 12 19:54:36 test ntpd[803]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 12 19:54:36 test cpufrequtils[800]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Apr 12 19:54:36 test systemd[1]: Started LSB: set CPUFreq kernel parameters. Apr 12 19:54:36 test bluetoothd[755]: Bluetooth daemon 5.50 Apr 12 19:54:36 test ifplugd[748]: Network Interface Plugging Daemon...start eth0...done. Apr 12 19:54:36 test systemd[1]: Started LSB: Brings up/down network automatically. Apr 12 19:54:36 test bluetoothd[755]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Apr 12 19:54:36 test systemd[1]: Started Bluetooth service. Apr 12 19:54:36 test systemd[1]: Reached target Bluetooth. Apr 12 19:54:36 test bluetoothd[755]: Starting SDP server Apr 12 19:54:36 test bluetoothd[755]: Excluding (cli) sap Apr 12 19:54:36 test kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Apr 12 19:54:36 test kernel: Bluetooth: BNEP filters: protocol multicast Apr 12 19:54:36 test kernel: Bluetooth: BNEP socket layer initialized Apr 12 19:54:36 test dbus-daemon[677]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=755 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Apr 12 19:54:36 test bluetoothd[755]: Bluetooth management interface 1.22 initialized Apr 12 19:54:36 test kernel: Bluetooth: MGMT ver 1.22 Apr 12 19:54:36 test systemd[1]: Starting Hostname Service... Apr 12 19:54:36 test bluetoothd[755]: Failed to set privacy: Rejected (0x0b) Apr 12 19:54:36 test dbus-daemon[677]: [system] Successfully activated service 'org.freedesktop.hostname1' Apr 12 19:54:36 test systemd[1]: Started Hostname Service. Apr 12 19:54:36 test nmbd[754]: [2024/04/12 19:54:36.366322, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Apr 12 19:54:36 test nmbd[754]: started asyncdns process 824 Apr 12 19:54:36 test nmbd[754]: [2024/04/12 19:54:36.367294, 0] ../lib/util/become_daemon.c:149(daemon_status) Apr 12 19:54:36 test nmbd[754]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Apr 12 19:54:36 test nmbd[754]: [2024/04/12 19:54:36.367361, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Apr 12 19:54:36 test nmbd[754]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Apr 12 19:54:36 test wireless.js[681]: Cleaning previous... Apr 12 19:54:36 test sudo[832]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 12 19:54:36 test sudo[832]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:36 test sudo[832]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:36 test sudo[834]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 12 19:54:36 test sudo[834]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:37 test ntpd[803]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 12 19:54:37 test sudo[834]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:37 test wireless.js[681]: Stopped aP Apr 12 19:54:37 test sudo[841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 12 19:54:37 test sudo[841]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:37 test sudo[841]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:37 test kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 12 19:54:37 test sudo[843]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Apr 12 19:54:37 test sudo[843]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:37 test sudo[843]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:37 test sudo[850]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 12 19:54:37 test sudo[850]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:37 test sudo[850]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:37 test sudo[852]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Apr 12 19:54:37 test sudo[852]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:38 test ntpd[803]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 12 19:54:39 test ntpd[803]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 12 19:54:39 test sh[557]: eth0: carrier acquired Apr 12 19:54:39 test dhcpcd[602]: eth0: carrier acquired Apr 12 19:54:39 test kernel: macb 1f00100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control tx Apr 12 19:54:39 test sh[557]: DUID 00:01:00:01:2d:69:1c:cc:2c:cf:67:26:5b:fb Apr 12 19:54:39 test sh[557]: eth0: IAID 67:26:5b:fb Apr 12 19:54:39 test dhcpcd[602]: DUID 00:01:00:01:2d:69:1c:cc:2c:cf:67:26:5b:fb Apr 12 19:54:39 test dhcpcd[602]: eth0: IAID 67:26:5b:fb Apr 12 19:54:39 test sh[557]: eth0: adding address fe80::7551:148:1f97:70b3 Apr 12 19:54:39 test sh[557]: ipv6_addaddr1: Permission denied Apr 12 19:54:39 test dhcpcd[602]: eth0: adding address fe80::7551:148:1f97:70b3 Apr 12 19:54:39 test dhcpcd[602]: ipv6_addaddr1: Permission denied Apr 12 19:54:39 test sudo[852]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:39 test wireless.js[681]: SETTING APPROPRIATE REG DOMAIN: DE Apr 12 19:54:39 test sudo[858]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 12 19:54:39 test sudo[858]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:39 test sudo[858]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:39 test sudo[860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Apr 12 19:54:39 test sudo[860]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:39 test sudo[860]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:39 test wireless.js[681]: SUCCESSFULLY SET NEW REGDOMAIN: DE Apr 12 19:54:39 test wireless.js[681]: Start wireless flow Apr 12 19:54:39 test wireless.js[681]: Stopped hotspot (if there).. Apr 12 19:54:39 test sudo[865]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 12 19:54:39 test sudo[865]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:39 test sudo[865]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:39 test sudo[867]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 12 19:54:39 test sudo[867]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:39 test sh[557]: eth0: soliciting a DHCP lease Apr 12 19:54:39 test dhcpcd[602]: eth0: soliciting a DHCP lease Apr 12 19:54:39 test sh[557]: eth0: soliciting an IPv6 router Apr 12 19:54:39 test dhcpcd[602]: eth0: soliciting an IPv6 router Apr 12 19:54:40 test ntpd[803]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 12 19:54:40 test systemd[1]: systemd-rfkill.service: Succeeded. Apr 12 19:54:40 test ifplugd(eth0)[799]: Link beat detected. Apr 12 19:54:40 test sudo[867]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:40 test wireless.js[681]: DHCP IP Apr 12 19:54:40 test wireless.js[681]: Start ap Apr 12 19:54:40 test wpa_supplicant[869]: Successfully initialized wpa_supplicant Apr 12 19:54:40 test sudo[870]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Apr 12 19:54:40 test sudo[870]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:40 test dhcpcd[871]: dev: loaded udev Apr 12 19:54:40 test kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 12 19:54:40 test dhcpcd-run-hooks[880]: wlan0: starting wpa_supplicant Apr 12 19:54:40 test ifplugd(eth0)[799]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Apr 12 19:54:40 test ifplugd(eth0)[799]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Apr 12 19:54:40 test dhcpcd-run-hooks[891]: wlan0: failed to start wpa_supplicant Apr 12 19:54:40 test dhcpcd-run-hooks[892]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Apr 12 19:54:40 test dhcpcd[871]: wlan0: connected to Access Point `' Apr 12 19:54:40 test dhcpcd[871]: DUID 00:01:00:01:2d:69:1c:cc:2c:cf:67:26:5b:fb Apr 12 19:54:40 test dhcpcd[871]: eth0: IAID 67:26:5b:fb Apr 12 19:54:40 test dhcpcd[871]: eth0: adding address fe80::7551:148:1f97:70b3 Apr 12 19:54:40 test dhcpcd[871]: ipv6_addaddr1: Permission denied Apr 12 19:54:40 test dhcpcd[871]: wlan0: waiting for carrier Apr 12 19:54:40 test dhcpcd[871]: eth0: soliciting a DHCP lease Apr 12 19:54:40 test dhcpcd[871]: eth0: soliciting an IPv6 router Apr 12 19:54:40 test bthelper[672]: Changing power off succeeded Apr 12 19:54:40 test volumio-remote-updater[674]: [2024-04-12 19:54:40] [info] asio async_connect error: system:111 (Connection refused) Apr 12 19:54:40 test volumio-remote-updater[674]: [2024-04-12 19:54:40] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 12 19:54:40 test volumio-remote-updater[674]: [2024-04-12 19:54:40] [error] handle_connect error: Underlying Transport Error Apr 12 19:54:40 test bthelper[672]: [CHG] Controller 2C:CF:67:26:5B:FD Class: 0x0000041c Apr 12 19:54:40 test bthelper[672]: Changing power on succeeded Apr 12 19:54:41 test wireless.js[681]: trying... Apr 12 19:54:41 test sudo[904]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:41 test sudo[904]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:41 test sudo[904]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:42 test wireless.js[681]: trying... Apr 12 19:54:42 test sudo[907]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:42 test sudo[907]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:42 test sudo[907]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:42 test wpa_supplicant[890]: wlan0: Trying to associate with SSID 'Brandosch' Apr 12 19:54:43 test wireless.js[681]: trying... Apr 12 19:54:43 test sudo[910]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:43 test sudo[910]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:43 test sudo[910]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:43 test sh[557]: eth0: offered 192.168.1.197 from 192.168.1.1 Apr 12 19:54:43 test dhcpcd[602]: eth0: offered 192.168.1.197 from 192.168.1.1 Apr 12 19:54:43 test dhcpcd[871]: eth0: offered 192.168.1.197 from 192.168.1.1 Apr 12 19:54:43 test sh[557]: eth0: probing address 192.168.1.197/24 Apr 12 19:54:43 test dhcpcd[602]: eth0: probing address 192.168.1.197/24 Apr 12 19:54:43 test dhcpcd[871]: eth0: probing address 192.168.1.197/24 Apr 12 19:54:44 test wireless.js[681]: trying... Apr 12 19:54:44 test sudo[913]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:44 test sudo[913]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:44 test sudo[913]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:45 test wireless.js[681]: trying... Apr 12 19:54:45 test sudo[916]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:45 test sudo[916]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:45 test sudo[916]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:45 test dhcpcd[871]: wlan0: carrier acquired Apr 12 19:54:45 test dhcpcd[871]: wlan0: connected to Access Point `Brandosch' Apr 12 19:54:45 test wpa_supplicant[890]: wlan0: Associated with d8:0d:17:a4:6c:1a Apr 12 19:54:45 test wpa_supplicant[890]: wlan0: CTRL-EVENT-CONNECTED - Connection to d8:0d:17:a4:6c:1a completed [id=0 id_str=] Apr 12 19:54:45 test wpa_supplicant[890]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 12 19:54:45 test wpa_supplicant[890]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Apr 12 19:54:45 test dhcpcd[871]: wlan0: IAID 67:26:5b:fc Apr 12 19:54:45 test dhcpcd[871]: wlan0: adding address fe80::73f1:8320:63be:6c4b Apr 12 19:54:45 test dhcpcd[871]: ipv6_addaddr1: Permission denied Apr 12 19:54:45 test dhcpcd[871]: wlan0: carrier lost Apr 12 19:54:45 test dhcpcd[871]: wlan0: carrier acquired Apr 12 19:54:45 test dhcpcd[871]: wlan0: IAID 67:26:5b:fc Apr 12 19:54:45 test dhcpcd[871]: wlan0: soliciting an IPv6 router Apr 12 19:54:46 test wireless.js[681]: trying... Apr 12 19:54:46 test sudo[931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:46 test sudo[931]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:46 test sudo[931]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:46 test wpa_supplicant[890]: RRM: Ignoring radio measurement request: Not RRM network Apr 12 19:54:46 test dhcpcd[871]: wlan0: rebinding lease of 192.168.1.201 Apr 12 19:54:46 test dhcpcd[871]: wlan0: probing address 192.168.1.201/24 Apr 12 19:54:47 test wireless.js[681]: trying... Apr 12 19:54:47 test sudo[934]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:47 test sudo[934]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:47 test sudo[934]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:48 test wireless.js[681]: trying... Apr 12 19:54:48 test sudo[937]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:48 test sudo[937]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:48 test sudo[937]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:48 test volumio-remote-updater[674]: [2024-04-12 19:54:48] [info] asio async_connect error: system:111 (Connection refused) Apr 12 19:54:48 test volumio-remote-updater[674]: [2024-04-12 19:54:48] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 12 19:54:48 test volumio-remote-updater[674]: [2024-04-12 19:54:48] [error] handle_connect error: Underlying Transport Error Apr 12 19:54:48 test dhcpcd[871]: eth0: leased 192.168.1.197 for 86400 seconds Apr 12 19:54:48 test avahi-daemon[673]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.197. Apr 12 19:54:48 test avahi-daemon[673]: New relevant interface eth0.IPv4 for mDNS. Apr 12 19:54:48 test dhcpcd[871]: eth0: adding route to 192.168.1.0/24 Apr 12 19:54:48 test avahi-daemon[673]: Registering new address record for 192.168.1.197 on eth0.IPv4. Apr 12 19:54:48 test dhcpcd[871]: eth0: adding default route via 192.168.1.1 Apr 12 19:54:48 test dhcpcd[871]: forked to background, child pid 959 Apr 12 19:54:48 test sudo[870]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:48 test sh[557]: eth0: leased 192.168.1.197 for 86400 seconds Apr 12 19:54:48 test sh[557]: eth0: adding route to 192.168.1.0/24 Apr 12 19:54:48 test sh[557]: eth0: adding default route via 192.168.1.1 Apr 12 19:54:48 test dhcpcd[602]: eth0: leased 192.168.1.197 for 86400 seconds Apr 12 19:54:48 test dhcpcd[602]: eth0: adding route to 192.168.1.0/24 Apr 12 19:54:48 test dhcpcd[602]: eth0: adding default route via 192.168.1.1 Apr 12 19:54:48 test sh[557]: forked to background, child pid 980 Apr 12 19:54:48 test dhcpcd[602]: forked to background, child pid 980 Apr 12 19:54:48 test ifplugd(eth0)[799]: client: ifup: interface eth0 already configured Apr 12 19:54:48 test sh[557]: eth0=eth0 Apr 12 19:54:48 test ifplugd(eth0)[799]: Program executed successfully. Apr 12 19:54:49 test wireless.js[681]: trying... Apr 12 19:54:49 test sudo[1007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:49 test sudo[1007]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:49 test sudo[1007]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:50 test ntpd[803]: Listen normally on 3 eth0 192.168.1.197:123 Apr 12 19:54:50 test ntpd[803]: new interface(s) found: waking up resolver Apr 12 19:54:50 test wireless.js[681]: trying... Apr 12 19:54:50 test sudo[1010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:50 test sudo[1010]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:50 test sudo[1010]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:51 test wireless.js[681]: trying... Apr 12 19:54:51 test sudo[1013]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:51 test sudo[1013]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:51 test sudo[1013]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:51 test nmbd[754]: [2024/04/12 19:54:51.372014, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 12 19:54:51 test systemd[1]: Started Samba NMB Daemon. Apr 12 19:54:51 test nmbd[754]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Apr 12 19:54:51 test nmbd[754]: [2024/04/12 19:54:51.379797, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Apr 12 19:54:51 test nmbd[754]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.197 for name WORKGROUP<1d>. Apr 12 19:54:51 test systemd[1]: Starting Samba Winbind Daemon... Apr 12 19:54:51 test nmbd[754]: This response was from IP 192.168.1.35, reporting an IP address of 192.168.1.35. Apr 12 19:54:51 test winbindd[1015]: [2024/04/12 19:54:51.509036, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 12 19:54:51 test winbindd[1015]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 12 19:54:51 test winbindd[1015]: [2024/04/12 19:54:51.520355, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 12 19:54:51 test winbindd[1015]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 12 19:54:51 test systemd[1]: Started Samba Winbind Daemon. Apr 12 19:54:51 test systemd[1]: Starting Samba SMB Daemon... Apr 12 19:54:51 test dhcpcd[959]: wlan0: leased 192.168.1.201 for 86400 seconds Apr 12 19:54:51 test avahi-daemon[673]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.201. Apr 12 19:54:51 test dhcpcd[959]: wlan0: adding route to 192.168.1.0/24 Apr 12 19:54:51 test avahi-daemon[673]: New relevant interface wlan0.IPv4 for mDNS. Apr 12 19:54:51 test dhcpcd[959]: wlan0: adding default route via 192.168.1.1 Apr 12 19:54:51 test avahi-daemon[673]: Registering new address record for 192.168.1.201 on wlan0.IPv4. Apr 12 19:54:51 test smbd[1020]: [2024/04/12 19:54:51.752099, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 12 19:54:51 test smbd[1020]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 12 19:54:51 test systemd[1]: Started Samba SMB Daemon. Apr 12 19:54:52 test wireless.js[681]: trying... Apr 12 19:54:52 test sudo[1049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 19:54:52 test sudo[1049]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:52 test sudo[1049]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:52 test wireless.js[681]: Connected to: ----Brandosch Apr 12 19:54:52 test wireless.js[681]: ---- Apr 12 19:54:52 test sudo[1052]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 19:54:52 test sudo[1052]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:52 test sudo[1052]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:52 test wireless.js[681]: ... joined AP, wlan0 IPv4 is 192.168.1.201, ipV6 is undefined Apr 12 19:54:52 test wireless.js[681]: It's done! AP Apr 12 19:54:52 test kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 12 19:54:52 test systemd[1]: Started Wireless Services. Apr 12 19:54:52 test systemd[1]: Started Volumio Backend Module. Apr 12 19:54:52 test systemd[1]: Started Volumio Cpu Tweaker. Apr 12 19:54:52 test systemd[1]: Reached target Multi-User System. Apr 12 19:54:52 test systemd[1]: Reached target Graphical Interface. Apr 12 19:54:52 test systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 12 19:54:52 test systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 12 19:54:52 test systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 12 19:54:52 test systemd[1]: Startup finished in 6.396s (kernel) + 18.937s (userspace) = 25.334s. Apr 12 19:54:52 test volumio-cpu-tweak[1058]: Setting RT Priority for mpd Apr 12 19:54:52 test volumio-cpu-tweak[1058]: pid 35's current scheduling policy: SCHED_OTHER Apr 12 19:54:52 test volumio-cpu-tweak[1058]: pid 35's current scheduling priority: 0 Apr 12 19:54:52 test volumio-cpu-tweak[1058]: Setting MPD Affinity Apr 12 19:54:52 test volumio-cpu-tweak[1058]: pid 3's current affinity mask: f Apr 12 19:54:52 test volumio-cpu-tweak[1058]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Apr 12 19:54:52 test volumio-cpu-tweak[1058]: VOLUMIO CPU TWEAK: Setting CPU Governor: conservative Apr 12 19:54:52 test systemd[1]: volumio_cpu_tweak.service: Succeeded. Apr 12 19:54:53 test ntpd[803]: Listen normally on 4 wlan0 192.168.1.201:123 Apr 12 19:54:53 test ntpd[803]: new interface(s) found: waking up resolver Apr 12 19:54:53 test volumio[1057]: info: ------------------------------------------- Apr 12 19:54:53 test volumio[1057]: info: ----- Volumio3 ---- Apr 12 19:54:53 test volumio[1057]: info: ------------------------------------------- Apr 12 19:54:53 test volumio[1057]: info: ----- System startup ---- Apr 12 19:54:53 test volumio[1057]: info: ------------------------------------------- Apr 12 19:54:53 test volumio[1057]: info: MYVOLUMIO Environment detected Apr 12 19:54:53 test volumio[1057]: info: Plugin folders cleanup Apr 12 19:54:53 test volumio[1057]: info: Scanning into folder /volumio/app/plugins/ Apr 12 19:54:53 test volumio[1057]: info: Scanning category audio_interface Apr 12 19:54:53 test volumio[1057]: info: Scanning category miscellanea Apr 12 19:54:53 test volumio[1057]: info: Scanning category music_service Apr 12 19:54:53 test volumio[1057]: info: Scanning category plugins.json Apr 12 19:54:53 test volumio[1057]: info: Scanning category system_controller Apr 12 19:54:53 test volumio[1057]: info: Scanning category user_interface Apr 12 19:54:53 test volumio[1057]: info: Scanning into folder /data/plugins/ Apr 12 19:54:53 test volumio[1057]: info: Scanning category audio_interface Apr 12 19:54:53 test volumio[1057]: info: Scanning category music_service Apr 12 19:54:53 test volumio[1057]: info: Plugin folders cleanup completed Apr 12 19:54:53 test volumio[1057]: info: ------------------------------------------- Apr 12 19:54:53 test volumio[1057]: info: ----- Core plugins startup ---- Apr 12 19:54:53 test volumio[1057]: info: ------------------------------------------- Apr 12 19:54:53 test volumio[1057]: info: Loading plugins from folder /volumio/app/plugins/ Apr 12 19:54:53 test volumio[1057]: info: Adding plugin upnp to MyMusic Plugins Apr 12 19:54:53 test volumio[1057]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 12 19:54:53 test volumio[1057]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 12 19:54:53 test volumio[1057]: info: Loading plugins from folder /data/plugins/ Apr 12 19:54:53 test volumio[1057]: info: Loading plugin "system"... Apr 12 19:54:53 test volumio[1057]: info: Loading plugin "appearance"... Apr 12 19:54:54 test volumio[1057]: info: Loading plugin "network"... Apr 12 19:54:54 test volumio[1057]: info: Refreshing Cached IP Addresses Apr 12 19:54:54 test sudo[1089]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 19:54:54 test sudo[1089]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:54 test volumio[1057]: info: Loading plugin "services"... Apr 12 19:54:54 test sudo[1091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 19:54:54 test sudo[1091]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:54 test sudo[1089]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:54 test volumio[1057]: info: Loading plugin "alsa_controller"... Apr 12 19:54:54 test sudo[1091]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:54 test sudo[1093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 12 19:54:54 test sudo[1093]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:54 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 19:54:54 test volumio[1057]: info: Loading plugin "wizard"... Apr 12 19:54:54 test volumio[1057]: info: Loading plugin "networkfs"... Apr 12 19:54:54 test volumio[1057]: info: Starting Udev Watcher for removable devices Apr 12 19:54:54 test sudo[1102]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Dan,password=Zuzana1979%,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.132/music /mnt/NAS/Synology Apr 12 19:54:54 test sudo[1102]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:54:54 test volumio[1057]: info: Ignoring mount for partition: boot Apr 12 19:54:54 test volumio[1057]: info: Ignoring mount for partition: volumio Apr 12 19:54:54 test volumio[1057]: info: Ignoring mount for partition: volumio_data Apr 12 19:54:54 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 19:54:54 test volumio[1057]: info: Loading plugin "volumio_command_line_client"... Apr 12 19:54:54 test volumio[1057]: info: Loading plugin "upnp"... Apr 12 19:54:54 test volumio[1057]: info: [1712944494693] Starting Upmpd Daemon Apr 12 19:54:54 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 19:54:54 test volumio[1057]: info: Loading plugin "my_music"... Apr 12 19:54:54 test volumio[1057]: info: Loading plugin "mpd"... Apr 12 19:54:54 test kernel: Key type cifs.spnego registered Apr 12 19:54:54 test kernel: Key type cifs.idmap registered Apr 12 19:54:54 test kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Apr 12 19:54:54 test kernel: CIFS: Attempting to mount \\192.168.1.132\music Apr 12 19:54:54 test sudo[1102]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:54 test volumio[1057]: info: Loading plugin "upnp_browser"... Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "alarm-clock"... Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "airplay_emulation"... Apr 12 19:54:55 test volumio[1057]: info: Starting Shairport Sync Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "last_100"... Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "webradio"... Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "i2s_dacs"... Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "volumiodiscovery"... Apr 12 19:54:55 test volumio[1057]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 12 19:54:55 test node[1057]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 12 19:54:55 test node[1057]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 19:54:55 test volumio[1057]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 19:54:55 test volumio[1057]: *** WARNING *** For more information see Apr 12 19:54:55 test volumio[1057]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 12 19:54:55 test volumio[1057]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 19:54:55 test volumio[1057]: *** WARNING *** For more information see Apr 12 19:54:55 test node[1057]: *** WARNING *** For more information see Apr 12 19:54:55 test node[1057]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 12 19:54:55 test node[1057]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 19:54:55 test node[1057]: *** WARNING *** For more information see Apr 12 19:54:55 test volumio[1057]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 12 19:54:55 test volumio[1057]: info: Discovery: Started advertising with name: Test Apr 12 19:54:55 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "spop"... Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "outputs"... Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "albumart"... Apr 12 19:54:55 test volumio[1057]: info: Plugin example_plugin is not enabled Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "inputs"... Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "updater_comm"... Apr 12 19:54:55 test volumio[1057]: info: Plugin mpdemulation is not enabled Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "rest_api"... Apr 12 19:54:55 test volumio[1057]: info: Loading plugin "websocket"... Apr 12 19:54:56 test volumio[1057]: info: Loading plugin "fusiondsp"... Apr 12 19:54:56 test volumio[1057]: Forking 3 albumart workers Apr 12 19:54:56 test volumio[1057]: info: Applying required configuration parameters for plugin fusiondsp Apr 12 19:54:56 test volumio[1057]: info: Loading i18n strings for locale cs Apr 12 19:54:56 test volumio[1057]: Updating browse sources language Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 19:54:56 test volumio[1057]: Starting albumart workers Apr 12 19:54:56 test volumio[1057]: Starting albumart workers Apr 12 19:54:56 test volumio[1057]: Starting albumart workers Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::initPlayerControls Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 19:54:56 test volumio[1057]: Express server listening on port 3000 Apr 12 19:54:56 test volumio[1057]: [Metrics] WebUI: 3s 356.84ms Apr 12 19:54:56 test volumio[1057]: info: CoreStateMachine::resetVolumioState Apr 12 19:54:56 test volumio[1057]: info: CoreStateMachine::getcurrentVolume Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioRetrievevolume Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.221 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 1 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.221 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 2 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.221 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 3 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.221 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 4 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 5 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 6 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.28 UA: okhttp/4.9.2 Total Clients: 7 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.28 UA: okhttp/4.9.2 Total Clients: 8 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 9 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 10 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 11 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 12 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 13 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.221 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 14 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 15 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 16 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 17 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 18 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 19 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201:3000 from 192.168.1.97 UA: node-XMLHttpRequest Total Clients: 20 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.221 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 21 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 19:54:56 test volumio[1057]: info: Reloading queue from file Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 22 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201:3000 from 192.168.1.15 UA: node-XMLHttpRequest Total Clients: 23 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 24 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 25 Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 26 Apr 12 19:54:56 test volumio[1057]: info: CoreStateMachine::setRepeat null single undefined Apr 12 19:54:56 test volumio[1057]: info: CoreStateMachine::pushState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioPushState Apr 12 19:54:56 test volumio[1057]: info: CoreStateMachine::setRandom null Apr 12 19:54:56 test volumio[1057]: info: CoreStateMachine::pushState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioPushState Apr 12 19:54:56 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 27 Apr 12 19:54:56 test volumio[1057]: info: Received Get System Info Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:54:56 test volumio[1057]: info: Discovery: Getting this device information Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 19:54:56 test volumio[1057]: info: Received Get System Info Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:54:56 test volumio[1057]: info: Discovery: Getting this device information Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: Listing playlists Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: VolumeController:: Volume=0 Mute =true Apr 12 19:54:56 test volumio[1057]: info: CoreStateMachine::pushState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioPushState Apr 12 19:54:56 test volumio[1057]: info: CoreStateMachine::updateTrackBlock Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrackBlock Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioRetrievevolume Apr 12 19:54:56 test volumio[1057]: info: Setting Device type: Raspberry PI Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: Discovery: adding 83ab2b0e-a3a4-4641-95e3-9cc0dde0ca06 Apr 12 19:54:56 test volumio[1057]: info: Discovery: Found device Obyvak Apr 12 19:54:56 test volumio[1057]: info: Discovery: Connecting to remote: 192.168.1.97 Apr 12 19:54:56 test volumio[1057]: info: Discovery: adding e0398273-9638-4903-840b-a591fc2df1ef Apr 12 19:54:56 test volumio[1057]: info: Discovery: Found device Garaz Apr 12 19:54:56 test volumio[1057]: info: Discovery: Connecting to remote: 192.168.1.15 Apr 12 19:54:56 test volumio[1057]: info: VolumeController:: Volume=0 Mute =true Apr 12 19:54:56 test volumio[1057]: info: CoreStateMachine::pushState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioPushState Apr 12 19:54:56 test volumio[1057]: info: Discovery: this is already registered, 83ab2b0e-a3a4-4641-95e3-9cc0dde0ca06 Apr 12 19:54:56 test volumio[1057]: info: Discovery: Found device Obyvak Apr 12 19:54:56 test volumio[1057]: info: Discovery: Connecting to remote: 192.168.1.97 Apr 12 19:54:56 test volumio[1057]: info: Discovery: this is already registered, e0398273-9638-4903-840b-a591fc2df1ef Apr 12 19:54:56 test volumio[1057]: info: Discovery: Found device Garaz Apr 12 19:54:56 test volumio[1057]: info: Discovery: Connecting to remote: 192.168.1.15 Apr 12 19:54:56 test volumio[1057]: info: Discovery: Connected to remote: 192.168.1.97 Apr 12 19:54:56 test volumio[1057]: info: Discovery: adding 9eb0d3b1-f3b3-4b0d-9e9f-9a708473034c Apr 12 19:54:56 test volumio[1057]: info: Discovery: Found device Test Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: Discovery: this is already registered, 9eb0d3b1-f3b3-4b0d-9e9f-9a708473034c Apr 12 19:54:56 test volumio[1057]: info: Discovery: Found device Test Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:56 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:56 test volumio[1057]: info: Discovery: Connected to remote: 192.168.1.15 Apr 12 19:54:56 test volumio[1057]: info: Discovery: adding e0a03639-1c77-462a-a44f-d415fc08829d Apr 12 19:54:56 test volumio[1057]: info: Discovery: Found device Kuchyne Apr 12 19:54:56 test volumio[1057]: info: Discovery: Connecting to remote: 192.168.1.211 Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 19:54:56 test volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 19:54:57 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 28 Apr 12 19:54:57 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 29 Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:57 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.201:3000 from 192.168.1.211 UA: node-XMLHttpRequest Total Clients: 29 Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 19:54:57 test volumio[1057]: info: Received Get System Info Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:54:57 test volumio[1057]: info: Discovery: Getting this device information Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:57 test volumio[1057]: info: Listing playlists Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetQueue Apr 12 19:54:57 test volumio[1057]: info: CoreStateMachine::getQueue Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getQueue Apr 12 19:54:57 test volumio[1057]: info: Received Get System Info Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:54:57 test volumio[1057]: info: Discovery: Getting this device information Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:54:57 test volumio[1057]: info: Discovery: Getting this device information Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:54:57 test volumio[1057]: info: Discovery: Getting this device information Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:54:57 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:54:57 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:54:58 test sudo[1093]: pam_unix(sudo:session): session closed for user root Apr 12 19:54:58 test volumio-remote-updater[674]: [2024-04-12 19:54:58] [connect] Successful connection Apr 12 19:54:58 test volumio-remote-updater[674]: [2024-04-12 19:54:58] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1712944498 101 Apr 12 19:54:58 test volumio[1057]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 30 Apr 12 19:54:58 test volumio[1057]: info: Discovery: Connected to remote: 192.168.1.211 Apr 12 19:54:58 test volumio[1057]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.124 UA: okhttp/4.9.2 Total Clients: 31 Apr 12 19:54:58 test volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 19:54:58 test volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 19:54:58 test volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 19:54:58 test volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 12 19:55:00 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Apr 12 19:55:00 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:55:00 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:55:04 test sudo[1203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 19:55:04 test sudo[1203]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:55:04 test sudo[1203]: pam_unix(sudo:session): session closed for user root Apr 12 19:55:04 test sudo[1205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 19:55:04 test sudo[1205]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:55:04 test sudo[1205]: pam_unix(sudo:session): session closed for user root Apr 12 19:55:04 test sudo[1209]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 12 19:55:04 test sudo[1209]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 12 19:55:04 test systemd[1]: Started UPnP Renderer front-end to MPD. Apr 12 19:55:04 test sudo[1209]: pam_unix(sudo:session): session closed for user root Apr 12 19:55:04 test volumio[1057]: info: Upmpdcli Daemon Started Apr 12 19:55:04 test volumio[1057]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 12 19:55:05 test systemd[1]: systemd-fsckd.service: Succeeded. Apr 12 19:55:05 test volumio[1057]: info: CoreCommandRouter::volumioPlay Apr 12 19:55:05 test volumio[1057]: info: CoreStateMachine::play index undefined Apr 12 19:55:05 test volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 19:55:05 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:55:05 test volumio[1057]: info: CoreStateMachine::startPlaybackTimer Apr 12 19:55:05 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:55:05 test volumio[1057]: verbose: ControllerMpd::clearAddPlayTracks NAS/Synology/--== FLAC ==--/Alice In Chains/Alice In Chains - 1996 - MTV Unplugged - FLAC/01 - Alice In Chains - Nutshell.flac Apr 12 19:55:05 test volumio[1057]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 19:55:06 test systemd[1]: systemd-hostnamed.service: Succeeded. Apr 12 19:55:06 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:55:06 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:55:06 test volumio[1057]: info: Discovery: Getting this device information Apr 12 19:55:06 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:55:06 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:55:06 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:55:06 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 19:55:06 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 19:55:06 test volumio[1057]: info: Discovery: Getting this device information Apr 12 19:55:06 test volumio[1057]: info: CoreCommandRouter::volumioGetState Apr 12 19:55:06 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:55:06 test volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 19:55:07 test volumio[1057]: info: CoreCommandRouter::volumioPlay Apr 12 19:55:07 test volumio[1057]: info: CoreStateMachine::play index undefined Apr 12 19:55:07 test volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 19:55:07 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:55:07 test volumio[1057]: info: CoreStateMachine::startPlaybackTimer Apr 12 19:55:07 test volumio[1057]: info: CorePlayQueue::getTrack 0 Apr 12 19:55:07 test volumio[1057]: verbose: ControllerMpd::clearAddPlayTracks NAS/Synology/--== FLAC ==--/Alice In Chains/Alice In Chains - 1996 - MTV Unplugged - FLAC/01 - Alice In Chains - Nutshell.flac Apr 12 19:55:07 test volumio[1057]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 19:55:08 test volumio[1057]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 12 19:55:11 test volumio[1057]: info: Preload queue cleared Apr 12 19:55:11 test volumio[1057]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 12 19:55:11 test volumio[1057]: info: CoreStateMachine::ClearQueue Apr 12 19:55:11 test volumio[1057]: info: CoreStateMachine::stop Apr 12 19:55:11 test volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 19:55:11 test volumio[1057]: info: CorePlayQueue::clearPlayQueue Apr 12 19:55:11 test volumio[1057]: info: CorePlayQueue::saveQueue Apr 12 19:55:11 test volumio[1057]: info: CoreCommandRouter::volumioPushQueue Apr 12 19:55:11 test volumio[1057]: info: CoreStateMachine::addQueueItems Apr 12 19:55:11 test volumio[1057]: info: CorePlayQueue::addQueueItems Apr 12 19:55:11 test volumio[1057]: info: Preload queue cleared Apr 12 19:55:11 test volumio[1057]: info: Adding Item to queue: music-library/NAS/Synology/--== FLAC ==--/Alice In Chains/Alice In Chains - 1996 - MTV Unplugged - FLAC/01 - Alice In Chains - Nutshell.flac Apr 12 19:55:11 test volumio[1057]: info: Exploding uri music-library/NAS/Synology/--== FLAC ==--/Alice In Chains/Alice In Chains - 1996 - MTV Unplugged - FLAC/01 - Alice In Chains - Nutshell.flac in service mpd Apr 12 19:55:11 test volumio[1057]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 19:55:11 test volumio[1057]: TypeError: Cannot read property 'then' of undefined Apr 12 19:55:11 test volumio[1057]: at ControllerMpd.scanFolder (/volumio/app/plugins/music_service/mpd/index.js:2527:19) Apr 12 19:55:11 test volumio[1057]: at ControllerMpd.explodeUri (/volumio/app/plugins/music_service/mpd/index.js:2325:21) Apr 12 19:55:11 test volumio[1057]: at CoreCommandRouter.explodeUriFromService (/volumio/app/index.js:1359:16) Apr 12 19:55:11 test volumio[1057]: at CorePlayQueue.explodeUriFromCache (/volumio/app/playqueue.js:123:24) Apr 12 19:55:11 test volumio[1057]: at CorePlayQueue.explodeUri (/volumio/app/playqueue.js:181:19) Apr 12 19:55:11 test volumio[1057]: at CorePlayQueue.addQueueItems (/volumio/app/playqueue.js:223:30) Apr 12 19:55:11 test volumio[1057]: at CoreStateMachine.addQueueItems (/volumio/app/statemachine.js:247:25) Apr 12 19:55:11 test volumio[1057]: at CoreCommandRouter.replaceAndPlay (/volumio/app/index.js:501:23) Apr 12 19:55:11 test volumio[1057]: at CoreCommandRouter.playItemsList (/volumio/app/index.js:477:17) Apr 12 19:55:11 test volumio[1057]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:118:33) Apr 12 19:55:11 test volumio[1057]: at Socket.emit (events.js:315:20) Apr 12 19:55:11 test volumio[1057]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Apr 12 19:55:11 test volumio[1057]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Apr 12 19:55:11 test volumio[1057]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 19:55:11 test sudo[1223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-12 19:54 Apr 12 19:55:11 test sudo[1223]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"