-- Logs begin at Thu 2019-02-14 18:11:59 HKT, end at Wed 2023-11-01 18:35:17 HKT. -- Nov 01 18:34:00 volumio-kh kernel: brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] Nov 01 18:34:00 volumio-kh kernel: brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 Nov 01 18:34:00 volumio-kh kernel: brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000 Nov 01 18:34:00 volumio-kh kernel: brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) Nov 01 18:34:00 volumio-kh kernel: brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 Nov 01 18:34:00 volumio-kh kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Nov 01 18:34:00 volumio-kh kernel: pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) Nov 01 18:34:00 volumio-kh kernel: pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 Nov 01 18:34:00 volumio-kh kernel: pci 0000:00:00.0: PME# supported from D0 D3hot Nov 01 18:34:00 volumio-kh kernel: PCI: bus0: Fast back to back transfers disabled Nov 01 18:34:00 volumio-kh kernel: pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 Nov 01 18:34:00 volumio-kh kernel: pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] Nov 01 18:34:00 volumio-kh kernel: pci 0000:01:00.0: PME# supported from D0 D3hot Nov 01 18:34:00 volumio-kh kernel: PCI: bus1: Fast back to back transfers disabled Nov 01 18:34:00 volumio-kh kernel: pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] Nov 01 18:34:00 volumio-kh kernel: pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] Nov 01 18:34:00 volumio-kh kernel: pci 0000:00:00.0: PCI bridge to [bus 01] Nov 01 18:34:00 volumio-kh kernel: pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] Nov 01 18:34:00 volumio-kh kernel: pcieport 0000:00:00.0: enabling device (0140 -> 0142) Nov 01 18:34:00 volumio-kh kernel: pcieport 0000:00:00.0: PME: Signaling with IRQ 62 Nov 01 18:34:00 volumio-kh kernel: bcm2708_fb soc:fb: FB found 1 display(s) Nov 01 18:34:00 volumio-kh kernel: Console: switching to colour frame buffer device 80x30 Nov 01 18:34:00 volumio-kh kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Nov 01 18:34:00 volumio-kh kernel: iproc-rng200 fe104000.rng: hwrng registered Nov 01 18:34:00 volumio-kh kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Nov 01 18:34:00 volumio-kh kernel: gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000 Nov 01 18:34:00 volumio-kh kernel: brd: module loaded Nov 01 18:34:00 volumio-kh kernel: loop: module loaded Nov 01 18:34:00 volumio-kh kernel: Loading iSCSI transport class v2.0-870. Nov 01 18:34:00 volumio-kh kernel: libphy: Fixed MDIO Bus: probed Nov 01 18:34:00 volumio-kh kernel: bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 Nov 01 18:34:00 volumio-kh kernel: libphy: bcmgenet MII bus: probed Nov 01 18:34:00 volumio-kh kernel: unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus Nov 01 18:34:00 volumio-kh kernel: usbcore: registered new interface driver r8152 Nov 01 18:34:00 volumio-kh kernel: usbcore: registered new interface driver lan78xx Nov 01 18:34:00 volumio-kh kernel: usbcore: registered new interface driver smsc95xx Nov 01 18:34:00 volumio-kh kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Nov 01 18:34:00 volumio-kh kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 Nov 01 18:34:00 volumio-kh kernel: xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x00000e0000000890 Nov 01 18:34:00 volumio-kh kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10 Nov 01 18:34:00 volumio-kh kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Nov 01 18:34:00 volumio-kh kernel: usb usb1: Product: xHCI Host Controller Nov 01 18:34:00 volumio-kh kernel: usb usb1: Manufacturer: Linux 5.10.92-v7l+ xhci-hcd Nov 01 18:34:00 volumio-kh kernel: usb usb1: SerialNumber: 0000:01:00.0 Nov 01 18:34:00 volumio-kh kernel: hub 1-0:1.0: USB hub found Nov 01 18:34:00 volumio-kh kernel: hub 1-0:1.0: 1 port detected Nov 01 18:34:00 volumio-kh kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Nov 01 18:34:00 volumio-kh kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Nov 01 18:34:00 volumio-kh kernel: xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Nov 01 18:34:00 volumio-kh kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10 Nov 01 18:34:00 volumio-kh kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Nov 01 18:34:00 volumio-kh kernel: usb usb2: Product: xHCI Host Controller Nov 01 18:34:00 volumio-kh kernel: usb usb2: Manufacturer: Linux 5.10.92-v7l+ xhci-hcd Nov 01 18:34:00 volumio-kh kernel: usb usb2: SerialNumber: 0000:01:00.0 Nov 01 18:34:00 volumio-kh kernel: hub 2-0:1.0: USB hub found Nov 01 18:34:00 volumio-kh kernel: hub 2-0:1.0: 4 ports detected Nov 01 18:34:00 volumio-kh kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Nov 01 18:34:00 volumio-kh kernel: dwc_otg: FIQ enabled Nov 01 18:34:00 volumio-kh kernel: dwc_otg: NAK holdoff enabled Nov 01 18:34:00 volumio-kh kernel: dwc_otg: FIQ split-transaction FSM enabled Nov 01 18:34:00 volumio-kh kernel: Module dwc_common_port init Nov 01 18:34:00 volumio-kh kernel: usbcore: registered new interface driver uas Nov 01 18:34:00 volumio-kh kernel: usbcore: registered new interface driver usb-storage Nov 01 18:34:00 volumio-kh kernel: mousedev: PS/2 mouse device common for all mice Nov 01 18:34:00 volumio-kh kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Nov 01 18:34:00 volumio-kh kernel: sdhci: Secure Digital Host Controller Interface driver Nov 01 18:34:00 volumio-kh kernel: sdhci: Copyright(c) Pierre Ossman Nov 01 18:34:00 volumio-kh kernel: mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe Nov 01 18:34:00 volumio-kh kernel: sdhci-pltfm: SDHCI platform and OF driver helper Nov 01 18:34:00 volumio-kh kernel: ledtrig-cpu: registered to indicate activity on CPUs Nov 01 18:34:00 volumio-kh kernel: hid: raw HID events driver (C) Jiri Kosina Nov 01 18:34:00 volumio-kh kernel: usbcore: registered new interface driver usbhid Nov 01 18:34:00 volumio-kh kernel: usbhid: USB HID core driver Nov 01 18:34:00 volumio-kh kernel: Initializing XFRM netlink socket Nov 01 18:34:00 volumio-kh kernel: NET: Registered protocol family 17 Nov 01 18:34:00 volumio-kh kernel: Key type dns_resolver registered Nov 01 18:34:00 volumio-kh kernel: Registering SWP/SWPB emulation handler Nov 01 18:34:00 volumio-kh kernel: registered taskstats version 1 Nov 01 18:34:00 volumio-kh kernel: Loading compiled-in X.509 certificates Nov 01 18:34:00 volumio-kh kernel: Key type ._fscrypt registered Nov 01 18:34:00 volumio-kh kernel: Key type .fscrypt registered Nov 01 18:34:00 volumio-kh kernel: Key type fscrypt-provisioning registered Nov 01 18:34:00 volumio-kh kernel: uart-pl011 fe201000.serial: there is not valid maps for state default Nov 01 18:34:00 volumio-kh kernel: uart-pl011 fe201000.serial: cts_event_workaround enabled Nov 01 18:34:00 volumio-kh kernel: fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 36, base_baud = 0) is a PL011 rev2 Nov 01 18:34:00 volumio-kh kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Nov 01 18:34:00 volumio-kh kernel: mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 Nov 01 18:34:00 volumio-kh kernel: mmc-bcm2835 fe300000.mmcnr: DMA channel allocated Nov 01 18:34:00 volumio-kh kernel: of_cfs_init Nov 01 18:34:00 volumio-kh kernel: of_cfs_init: OK Nov 01 18:34:00 volumio-kh kernel: mmc1: queuing unknown CIS tuple 0x80 (2 bytes) Nov 01 18:34:00 volumio-kh kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Nov 01 18:34:00 volumio-kh kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Nov 01 18:34:00 volumio-kh kernel: mmc1: queuing unknown CIS tuple 0x80 (7 bytes) Nov 01 18:34:00 volumio-kh kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Nov 01 18:34:00 volumio-kh kernel: mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA Nov 01 18:34:00 volumio-kh kernel: Freeing unused kernel memory: 2048K Nov 01 18:34:00 volumio-kh kernel: Run /init as init process Nov 01 18:34:00 volumio-kh kernel: with arguments: Nov 01 18:34:00 volumio-kh kernel: /init Nov 01 18:34:00 volumio-kh kernel: splash Nov 01 18:34:00 volumio-kh kernel: with environment: Nov 01 18:34:00 volumio-kh kernel: HOME=/ Nov 01 18:34:00 volumio-kh kernel: TERM=linux Nov 01 18:34:00 volumio-kh kernel: imgpart=/dev/mmcblk0p2 Nov 01 18:34:00 volumio-kh kernel: imgfile=/volumio_current.sqsh Nov 01 18:34:00 volumio-kh kernel: bootdelay=5 Nov 01 18:34:00 volumio-kh kernel: mmc1: new high speed SDIO card at address 0001 Nov 01 18:34:00 volumio-kh kernel: mmc0: new ultra high speed DDR50 SDHC card at address e624 Nov 01 18:34:00 volumio-kh kernel: mmcblk0: mmc0:e624 SD32G 29.7 GiB Nov 01 18:34:00 volumio-kh kernel: mmcblk0: p1 p2 p3 Nov 01 18:34:00 volumio-kh kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd Nov 01 18:34:00 volumio-kh initramfs: Booting Volumio for BCM2711 Nov 01 18:34:00 volumio-kh initramfs: This script mounts rootfs RO with an overlay RW layer. Nov 01 18:34:00 volumio-kh kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Nov 01 18:34:00 volumio-kh initramfs: IMGPART=/dev/mmcblk0p2 Nov 01 18:34:00 volumio-kh initramfs: IMGFILE=/volumio_current.sqsh Nov 01 18:34:00 volumio-kh initramfs: Boot delay (except first time) will be 5 seconds Nov 01 18:34:00 volumio-kh initramfs: /dev/mmcblk0p2: Nov 01 18:34:00 volumio-kh kernel: EXT4-fs (mmcblk0p2): recovery complete Nov 01 18:34:00 volumio-kh kernel: usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 Nov 01 18:34:00 volumio-kh kernel: usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Nov 01 18:34:00 volumio-kh kernel: usb 1-1: Product: USB2.0 Hub Nov 01 18:34:00 volumio-kh kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) Nov 01 18:34:00 volumio-kh kernel: hub 1-1:1.0: USB hub found Nov 01 18:34:00 volumio-kh kernel: hub 1-1:1.0: 4 ports detected Nov 01 18:34:00 volumio-kh initramfs: Doing a 5 second delay here to give kernel load a headstart Nov 01 18:34:00 volumio-kh kernel: usb 1-1.2: new high-speed USB device number 3 using xhci_hcd Nov 01 18:34:00 volumio-kh kernel: usb 1-1.2: New USB device found, idVendor=20b1, idProduct=3033, bcdDevice= 0.01 Nov 01 18:34:00 volumio-kh kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=3, SerialNumber=2 Nov 01 18:34:00 volumio-kh kernel: usb 1-1.2: Product: Gustard USB Audio 2.0 Nov 01 18:34:00 volumio-kh kernel: usb 1-1.2: Manufacturer: Gustard Nov 01 18:34:00 volumio-kh kernel: hid-generic 0003:20B1:3033.0001: hiddev96,hidraw0: USB HID v1.10 Device [Gustard Gustard USB Audio 2.0] on usb-0000:01:00.0-1.2/input3 Nov 01 18:34:00 volumio-kh initramfs: Checking for USB updates Nov 01 18:34:00 volumio-kh initramfs: No USB device detected (when incorrect, try adding 'bootdelay=5' to your boot cmdline) Nov 01 18:34:00 volumio-kh kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Nov 01 18:34:00 volumio-kh kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Nov 01 18:34:00 volumio-kh kernel: EXT4-fs (mmcblk0p3): recovery complete Nov 01 18:34:00 volumio-kh kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null) Nov 01 18:34:00 volumio-kh initramfs: With Option: Nov 01 18:34:00 volumio-kh initramfs: VOLUMIO_VERSION="3.546" Nov 01 18:34:00 volumio-kh initramfs: Finish initramfs, continue booting Volumio Nov 01 18:34:00 volumio-kh systemd[1]: System time before build time, advancing clock. Nov 01 18:34:00 volumio-kh kernel: NET: Registered protocol family 10 Nov 01 18:34:00 volumio-kh kernel: Segment Routing with IPv6 Nov 01 18:34:00 volumio-kh systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) Nov 01 18:34:00 volumio-kh systemd[1]: Detected architecture arm. Nov 01 18:34:00 volumio-kh systemd[1]: Set hostname to . Nov 01 18:34:00 volumio-kh systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Nov 01 18:34:00 volumio-kh kernel: random: systemd: uninitialized urandom read (16 bytes read) Nov 01 18:34:00 volumio-kh kernel: random: systemd: uninitialized urandom read (16 bytes read) Nov 01 18:34:00 volumio-kh kernel: random: systemd: uninitialized urandom read (16 bytes read) Nov 01 18:34:00 volumio-kh systemd[1]: Listening on udev Control Socket. Nov 01 18:34:00 volumio-kh systemd[1]: Started Forward Password Requests to Wall Directory Watch. Nov 01 18:34:00 volumio-kh systemd[1]: Created slice User and Session Slice. Nov 01 18:34:00 volumio-kh systemd[1]: Listening on udev Kernel Socket. Nov 01 18:34:00 volumio-kh systemd[1]: Listening on Journal Socket. Nov 01 18:34:00 volumio-kh systemd[1]: Starting udev Coldplug all Devices... Nov 01 18:34:00 volumio-kh kernel: i2c /dev entries driver Nov 01 18:34:00 volumio-kh systemd-journald[201]: Journal started Nov 01 18:34:00 volumio-kh systemd-journald[201]: Runtime journal (/run/log/journal/3c3812e622e46b6dc8110864638cf76c) is 7.5M, max 30.0M, 22.5M free. Nov 01 18:34:00 volumio-kh systemd-modules-load[200]: Inserted module 'i2c_dev' Nov 01 18:34:00 volumio-kh fake-hwclock[203]: Wed Nov 1 10:34:00 UTC 2023 Nov 01 18:34:00 volumio-kh systemd[1]: dynamicswap.service: Succeeded. Nov 01 18:34:00 volumio-kh systemd[1]: Started Create System Users. Nov 01 18:34:00 volumio-kh systemd[1]: Starting Create Static Device Nodes in /dev... Nov 01 18:34:00 volumio-kh systemd[1]: Started Create Static Device Nodes in /dev. Nov 01 18:34:00 volumio-kh systemd[1]: Reached target Local File Systems (Pre). Nov 01 18:34:00 volumio-kh systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Nov 01 18:34:00 volumio-kh systemd[1]: Mounting /tmp... Nov 01 18:34:00 volumio-kh systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Nov 01 18:34:00 volumio-kh systemd[1]: Mounting /var/log... Nov 01 18:34:00 volumio-kh systemd[1]: Mounting /var/spool/cups... Nov 01 18:34:00 volumio-kh systemd[1]: Starting udev Kernel Device Manager... Nov 01 18:34:00 volumio-kh systemd[1]: Mounted /tmp. Nov 01 18:34:00 volumio-kh systemd[1]: Started udev Coldplug all Devices. Nov 01 18:34:00 volumio-kh systemd[1]: Mounted /var/log. Nov 01 18:34:00 volumio-kh systemd[1]: Mounted /var/spool/cups. Nov 01 18:34:00 volumio-kh systemd[1]: Mounting /var/spool/cups/tmp... Nov 01 18:34:00 volumio-kh systemd[1]: Starting Flush Journal to Persistent Storage... Nov 01 18:34:00 volumio-kh systemd[1]: Starting Helper to synchronize boot up for ifupdown... Nov 01 18:34:00 volumio-kh systemd[1]: Mounted /var/spool/cups/tmp. Nov 01 18:34:00 volumio-kh systemd-udevd[226]: Network interface NamePolicy= disabled on kernel command line, ignoring. Nov 01 18:34:00 volumio-kh systemd-journald[201]: Runtime journal (/run/log/journal/3c3812e622e46b6dc8110864638cf76c) is 7.5M, max 30.0M, 22.5M free. Nov 01 18:34:00 volumio-kh systemd[1]: Started Flush Journal to Persistent Storage. Nov 01 18:34:00 volumio-kh systemd[1]: Started udev Kernel Device Manager. Nov 01 18:34:00 volumio-kh systemd[1]: Starting Show Plymouth Boot Screen... Nov 01 18:34:00 volumio-kh systemd[1]: Received SIGRTMIN+20 from PID 247 (plymouthd). Nov 01 18:34:00 volumio-kh systemd[1]: Started Show Plymouth Boot Screen. Nov 01 18:34:00 volumio-kh systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Nov 01 18:34:00 volumio-kh systemd[1]: Reached target Local Encrypted Volumes. Nov 01 18:34:00 volumio-kh systemd[1]: Reached target Paths. Nov 01 18:34:00 volumio-kh systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Nov 01 18:34:00 volumio-kh kernel: rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000 Nov 01 18:34:00 volumio-kh kernel: rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000 Nov 01 18:34:00 volumio-kh systemd-udevd[237]: Using default interface naming scheme 'v240'. Nov 01 18:34:00 volumio-kh kernel: rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000 Nov 01 18:34:00 volumio-kh kernel: rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000 Nov 01 18:34:00 volumio-kh kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Nov 01 18:34:00 volumio-kh kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Nov 01 18:34:00 volumio-kh kernel: [vc_sm_connected_init]: start Nov 01 18:34:00 volumio-kh kernel: [vc_sm_connected_init]: installed successfully Nov 01 18:34:00 volumio-kh kernel: mc: Linux media interface: v0.10 Nov 01 18:34:00 volumio-kh systemd-udevd[237]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 01 18:34:01 volumio-kh systemd-udevd[236]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 01 18:34:01 volumio-kh kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Nov 01 18:34:01 volumio-kh kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Nov 01 18:34:01 volumio-kh kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Nov 01 18:34:01 volumio-kh kernel: videodev: Linux video capture interface: v2.00 Nov 01 18:34:01 volumio-kh kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 01 18:34:01 volumio-kh kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Nov 01 18:34:01 volumio-kh kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Nov 01 18:34:01 volumio-kh kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Nov 01 18:34:01 volumio-kh kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Nov 01 18:34:01 volumio-kh kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Nov 01 18:34:01 volumio-kh kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Nov 01 18:34:01 volumio-kh kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Nov 01 18:34:01 volumio-kh kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Nov 01 18:34:01 volumio-kh kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Nov 01 18:34:01 volumio-kh kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Nov 01 18:34:01 volumio-kh kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Nov 01 18:34:01 volumio-kh kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Nov 01 18:34:01 volumio-kh kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Nov 01 18:34:02 volumio-kh kernel: snd_usb_audio: unknown parameter 'nrpacks' ignored Nov 01 18:34:02 volumio-kh kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Nov 01 18:34:02 volumio-kh kernel: cfg80211: loaded regulatory.db is malformed or signature is missing/invalid Nov 01 18:34:02 volumio-kh kernel: usb 1-1.2: 1:3 : unsupported format bits 0x100000000 Nov 01 18:34:02 volumio-kh kernel: usbcore: registered new interface driver snd-usb-audio Nov 01 18:34:02 volumio-kh kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Nov 01 18:34:02 volumio-kh kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Nov 01 18:34:02 volumio-kh kernel: usbcore: registered new interface driver brcmfmac Nov 01 18:34:02 volumio-kh systemd[1]: Found device /dev/mmcblk0p1. Nov 01 18:34:03 volumio-kh kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Nov 01 18:34:03 volumio-kh 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 Nov 01 18:34:03 volumio-kh systemd-udevd[248]: Using default interface naming scheme 'v240'. Nov 01 18:34:03 volumio-kh systemd-udevd[248]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 01 18:34:04 volumio-kh systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Nov 01 18:34:04 volumio-kh systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Nov 01 18:34:04 volumio-kh systemd[1]: Condition check resulted in Huge Pages File System being skipped. Nov 01 18:34:04 volumio-kh systemd[1]: Condition check resulted in FUSE Control File System being skipped. Nov 01 18:34:04 volumio-kh systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Nov 01 18:34:04 volumio-kh systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Nov 01 18:34:04 volumio-kh systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Nov 01 18:34:04 volumio-kh systemd[1]: Starting File System Check on /dev/mmcblk0p1... Nov 01 18:34:04 volumio-kh systemd[1]: Starting Load/Save RF Kill Switch Status... Nov 01 18:34:04 volumio-kh systemd[1]: Started File System Check Daemon to report status. Nov 01 18:34:04 volumio-kh systemd[1]: Started Load/Save RF Kill Switch Status. Nov 01 18:34:04 volumio-kh systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Nov 01 18:34:04 volumio-kh systemd-fsck[378]: fsck.fat 4.1 (2017-01-24) Nov 01 18:34:04 volumio-kh systemd-fsck[378]: 0x41: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Nov 01 18:34:04 volumio-kh systemd-fsck[378]: Automatically removing dirty bit. Nov 01 18:34:04 volumio-kh systemd-fsck[378]: Performing changes. Nov 01 18:34:04 volumio-kh systemd-fsck[378]: /dev/mmcblk0p1: 307 files, 109537/123044 clusters Nov 01 18:34:04 volumio-kh systemd[1]: Started File System Check on /dev/mmcblk0p1. Nov 01 18:34:04 volumio-kh systemd[1]: Mounting /boot... Nov 01 18:34:04 volumio-kh systemd[1]: Mounted /boot. Nov 01 18:34:04 volumio-kh systemd[1]: Reached target Local File Systems. Nov 01 18:34:04 volumio-kh systemd[1]: Started ifup for eth0. Nov 01 18:34:04 volumio-kh systemd[1]: Started ifup for wlan0. Nov 01 18:34:04 volumio-kh systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Nov 01 18:34:04 volumio-kh systemd[1]: Starting Preprocess NFS configuration... Nov 01 18:34:04 volumio-kh systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Nov 01 18:34:04 volumio-kh systemd[1]: Starting Create Volatile Files and Directories... Nov 01 18:34:04 volumio-kh systemd[1]: nfs-config.service: Succeeded. Nov 01 18:34:04 volumio-kh systemd[1]: Started Preprocess NFS configuration. Nov 01 18:34:04 volumio-kh systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Nov 01 18:34:04 volumio-kh systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Nov 01 18:34:04 volumio-kh systemd[1]: Reached target NFS client services. Nov 01 18:34:04 volumio-kh systemd[1]: Started Create Volatile Files and Directories. Nov 01 18:34:05 volumio-kh systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Nov 01 18:34:05 volumio-kh systemd[1]: Starting RPC bind portmap service... Nov 01 18:34:05 volumio-kh systemd[1]: Starting Update UTMP about System Boot/Shutdown... Nov 01 18:34:05 volumio-kh systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Nov 01 18:34:05 volumio-kh systemd[1]: Started Update UTMP about System Boot/Shutdown. Nov 01 18:34:05 volumio-kh kernel: 8021q: 802.1Q VLAN Support v1.8 Nov 01 18:34:05 volumio-kh systemd[1]: Started RPC bind portmap service. Nov 01 18:34:05 volumio-kh systemd[1]: Reached target Remote File Systems (Pre). Nov 01 18:34:05 volumio-kh systemd[1]: Reached target Remote File Systems. Nov 01 18:34:05 volumio-kh systemd[1]: Reached target RPC Port Mapper. Nov 01 18:34:05 volumio-kh kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 01 18:34:05 volumio-kh sh[385]: eth0: waiting for carrier Nov 01 18:34:05 volumio-kh dhcpcd[421]: eth0: waiting for carrier Nov 01 18:34:05 volumio-kh systemd[1]: Received SIGRTMIN+20 from PID 247 (plymouthd). Nov 01 18:34:05 volumio-kh systemd[1]: plymouth-read-write.service: Succeeded. Nov 01 18:34:05 volumio-kh kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Nov 01 18:34:05 volumio-kh kernel: bcmgenet fd580000.ethernet eth0: Link is Down Nov 01 18:34:05 volumio-kh systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Nov 01 18:34:05 volumio-kh systemd[1]: Reached target System Initialization. Nov 01 18:34:05 volumio-kh systemd[1]: Started Daily Cleanup of Temporary Directories. Nov 01 18:34:05 volumio-kh systemd[1]: Listening on mpd.socket. Nov 01 18:34:05 volumio-kh systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Nov 01 18:34:05 volumio-kh systemd[1]: Listening on triggerhappy.socket. Nov 01 18:34:05 volumio-kh systemd[1]: apt-daily.timer: Not using persistent file timestamp Fri 2025-01-17 21:33:30 HKT as it is in the future. Nov 01 18:34:05 volumio-kh systemd[1]: Started Daily apt download activities. Nov 01 18:34:05 volumio-kh systemd[1]: apt-daily-upgrade.timer: Not using persistent file timestamp Fri 2025-01-17 21:33:30 HKT as it is in the future. Nov 01 18:34:05 volumio-kh systemd-udevd[239]: Process '/bin/bash -c '/usr/local/bin/volumio usbattach'' failed with exit code 7. Nov 01 18:34:05 volumio-kh systemd[1]: Started Daily apt upgrade and clean activities. Nov 01 18:34:05 volumio-kh systemd[1]: Reached target Timers. Nov 01 18:34:05 volumio-kh systemd[1]: Listening on D-Bus System Message Bus Socket. Nov 01 18:34:05 volumio-kh systemd[1]: Reached target Sockets. Nov 01 18:34:05 volumio-kh systemd[1]: Reached target Basic System. Nov 01 18:34:05 volumio-kh systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Nov 01 18:34:05 volumio-kh systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Nov 01 18:34:05 volumio-kh systemd[1]: Started volumio-remote-updater.service. Nov 01 18:34:05 volumio-kh systemd[1]: Starting Wireless Services... Nov 01 18:34:05 volumio-kh systemd[1]: Started UPnP Renderer front-end to MPD. Nov 01 18:34:05 volumio-kh systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Nov 01 18:34:05 volumio-kh systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Nov 01 18:34:05 volumio-kh systemd[1]: Started Manage Sound Card State (restore and store). Nov 01 18:34:05 volumio-kh alsactl[467]: alsactl 1.1.8 daemon started Nov 01 18:34:05 volumio-kh systemd[1]: Starting Save/Restore Sound Card State... Nov 01 18:34:05 volumio-kh systemd[1]: Starting Configure Bluetooth Modems connected by UART... Nov 01 18:34:05 volumio-kh systemd[1]: Started Volumio Iptables Module. Nov 01 18:34:05 volumio-kh systemd[1]: Starting Login Service... Nov 01 18:34:05 volumio-kh systemd[1]: Starting dhcpcd on all interfaces... Nov 01 18:34:05 volumio-kh systemd[1]: Starting triggerhappy global hotkey daemon... Nov 01 18:34:05 volumio-kh systemd[1]: Started D-Bus System Message Bus. Nov 01 18:34:05 volumio-kh dhcpcd[473]: Not running dhcpcd because /etc/network/interfaces Nov 01 18:34:05 volumio-kh dhcpcd[473]: defines some interfaces that will use a Nov 01 18:34:05 volumio-kh dhcpcd[473]: DHCP client or static address Nov 01 18:34:05 volumio-kh systemd[1]: Starting WPA supplicant... Nov 01 18:34:05 volumio-kh systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Nov 01 18:34:05 volumio-kh systemd[1]: Started Helper to synchronize boot up for ifupdown. Nov 01 18:34:05 volumio-kh systemd[1]: Started Save/Restore Sound Card State. Nov 01 18:34:05 volumio-kh systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Nov 01 18:34:05 volumio-kh thd[474]: Unable to parse trigger line: Nov 01 18:34:05 volumio-kh thd[474]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Nov 01 18:34:05 volumio-kh thd[474]: Unable to parse trigger line: Nov 01 18:34:05 volumio-kh thd[474]: Found socket passed from systemd Nov 01 18:34:05 volumio-kh systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Nov 01 18:34:05 volumio-kh systemd[1]: Failed to start dhcpcd on all interfaces. Nov 01 18:34:05 volumio-kh systemd[1]: Started triggerhappy global hotkey daemon. Nov 01 18:34:06 volumio-kh systemd[1]: Reached target Sound Card. Nov 01 18:34:06 volumio-kh systemd[1]: Starting Raise network interfaces... Nov 01 18:34:06 volumio-kh sh[386]: wlan0=wlan0 Nov 01 18:34:06 volumio-kh kernel: uart-pl011 fe201000.serial: no DMA platform data Nov 01 18:34:06 volumio-kh systemd-logind[472]: New seat seat0. Nov 01 18:34:06 volumio-kh avahi-daemon[482]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Nov 01 18:34:06 volumio-kh avahi-daemon[482]: Successfully dropped root privileges. Nov 01 18:34:06 volumio-kh avahi-daemon[482]: avahi-daemon 0.7 starting up. Nov 01 18:34:06 volumio-kh loadcpufreq[460]: Loading cpufreq kernel modules...done (none). Nov 01 18:34:06 volumio-kh systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Nov 01 18:34:06 volumio-kh avahi-daemon[482]: Successfully called chroot(). Nov 01 18:34:06 volumio-kh avahi-daemon[482]: Successfully dropped remaining capabilities. Nov 01 18:34:06 volumio-kh avahi-daemon[482]: Loading service file /services/volumio.service. Nov 01 18:34:06 volumio-kh systemd[1]: Started Login Service. Nov 01 18:34:06 volumio-kh systemd[1]: Started Avahi mDNS/DNS-SD Stack. Nov 01 18:34:06 volumio-kh avahi-daemon[482]: Network interface enumeration completed. Nov 01 18:34:06 volumio-kh avahi-daemon[482]: Server startup complete. Host name is volumio-kh.local. Local service cookie is 770998405. Nov 01 18:34:06 volumio-kh avahi-daemon[482]: Service "Volumio-kh" (/services/volumio.service) successfully established. Nov 01 18:34:06 volumio-kh systemd[1]: Starting LSB: set CPUFreq kernel parameters... Nov 01 18:34:07 volumio-kh systemd[1]: Started Raise network interfaces. Nov 01 18:34:07 volumio-kh cpufrequtils[563]: CPUFreq Utilities: Setting performance CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Nov 01 18:34:07 volumio-kh systemd[1]: Started LSB: set CPUFreq kernel parameters. Nov 01 18:34:07 volumio-kh volumio-remote-updater[463]: Error: No active session Nov 01 18:34:07 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:07] [info] asio async_connect error: system:111 (Connection refused) Nov 01 18:34:07 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:07] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 01 18:34:07 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:07] [error] handle_connect error: Underlying Transport Error Nov 01 18:34:07 volumio-kh systemd[1]: Started WPA supplicant. Nov 01 18:34:07 volumio-kh systemd[1]: Reached target Network. Nov 01 18:34:07 volumio-kh systemd[1]: Reached target Network is Online. Nov 01 18:34:07 volumio-kh systemd[1]: Starting LSB: Brings up/down network automatically... Nov 01 18:34:07 volumio-kh systemd[1]: Starting /etc/rc.local Compatibility... Nov 01 18:34:07 volumio-kh wpa_supplicant[479]: Successfully initialized wpa_supplicant Nov 01 18:34:07 volumio-kh systemd[1]: Starting Network Time Service... Nov 01 18:34:07 volumio-kh systemd[1]: Starting Permit User Sessions... Nov 01 18:34:07 volumio-kh systemd[1]: Starting Samba NMB Daemon... Nov 01 18:34:07 volumio-kh systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 01 18:34:07 volumio-kh systemd[1]: Starting Music Player Daemon... Nov 01 18:34:07 volumio-kh systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Nov 01 18:34:07 volumio-kh systemd[1]: Started /etc/rc.local Compatibility. Nov 01 18:34:07 volumio-kh volumio[466]: Could not open config: /tmp/upmpdcli.conf Nov 01 18:34:07 volumio-kh systemd[1]: Started Permit User Sessions. Nov 01 18:34:07 volumio-kh systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:34:07 volumio-kh systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Nov 01 18:34:07 volumio-kh systemd[1]: Starting Hold until boot process finishes up... Nov 01 18:34:07 volumio-kh systemd[1]: Starting Terminate Plymouth Boot Screen... Nov 01 18:34:07 volumio-kh systemd[1]: plymouth-start.service: Succeeded. Nov 01 18:34:07 volumio-kh systemd[1]: plymouth-quit-wait.service: Succeeded. Nov 01 18:34:07 volumio-kh systemd[1]: Started Hold until boot process finishes up. Nov 01 18:34:07 volumio-kh systemd[1]: plymouth-quit.service: Succeeded. Nov 01 18:34:07 volumio-kh systemd[1]: Started Terminate Plymouth Boot Screen. Nov 01 18:34:07 volumio-kh systemd[1]: Received SIGRTMIN+21 from PID 247 (n/a). Nov 01 18:34:07 volumio-kh systemd[1]: Received SIGRTMIN+21 from PID 247 (n/a). Nov 01 18:34:07 volumio-kh ifplugd(eth0)[625]: ifplugd 0.28 initializing. Nov 01 18:34:07 volumio-kh systemd[1]: Started Getty on tty1. Nov 01 18:34:07 volumio-kh systemd[1]: Reached target Login Prompts. Nov 01 18:34:07 volumio-kh ifplugd(eth0)[625]: Using interface eth0/DC:A6:32:FA:57:A6 with driver (version: 5.10.92-v7l+) Nov 01 18:34:07 volumio-kh ifplugd(eth0)[625]: Using detection mode: SIOCETHTOOL Nov 01 18:34:07 volumio-kh ifplugd(eth0)[625]: Initialization complete, link beat not detected. Nov 01 18:34:07 volumio-kh ntpd[599]: ntpd 4.2.8p12@1.3728-o (1): Starting Nov 01 18:34:07 volumio-kh ntpd[599]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Nov 01 18:34:07 volumio-kh systemd[1]: Started Network Time Service. Nov 01 18:34:07 volumio-kh ntpd[630]: proto: precision = 0.778 usec (-20) Nov 01 18:34:07 volumio-kh ifplugd[596]: Network Interface Plugging Daemon...start eth0...done. Nov 01 18:34:07 volumio-kh ntpd[630]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Nov 01 18:34:07 volumio-kh systemd[1]: Started LSB: Brings up/down network automatically. Nov 01 18:34:07 volumio-kh ntpd[630]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2023-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Nov 01 18:34:07 volumio-kh ntpd[630]: Listen and drop on 0 v6wildcard [::]:123 Nov 01 18:34:07 volumio-kh ntpd[630]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Nov 01 18:34:07 volumio-kh ntpd[630]: Listen normally on 2 lo 127.0.0.1:123 Nov 01 18:34:07 volumio-kh ntpd[630]: Listening on routing socket on fd #19 for interface updates Nov 01 18:34:07 volumio-kh ntpd[630]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 01 18:34:07 volumio-kh ntpd[630]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 01 18:34:07 volumio-kh systemd[1]: iptables.service: Succeeded. Nov 01 18:34:07 volumio-kh haveged[413]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Nov 01 18:34:07 volumio-kh haveged[413]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Nov 01 18:34:07 volumio-kh haveged[413]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99668 Nov 01 18:34:07 volumio-kh haveged[413]: haveged: fills: 0, generated: 0 Nov 01 18:34:08 volumio-kh kernel: random: crng init done Nov 01 18:34:08 volumio-kh kernel: random: 7 urandom warning(s) missed due to ratelimiting Nov 01 18:34:08 volumio-kh ntpd[630]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Nov 01 18:34:08 volumio-kh nmbd[610]: [2023/11/01 18:34:08.818133, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Nov 01 18:34:08 volumio-kh nmbd[610]: started asyncdns process 643 Nov 01 18:34:08 volumio-kh nmbd[610]: [2023/11/01 18:34:08.822384, 0] ../lib/util/become_daemon.c:149(daemon_status) Nov 01 18:34:08 volumio-kh nmbd[610]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Nov 01 18:34:08 volumio-kh nmbd[610]: [2023/11/01 18:34:08.823052, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Nov 01 18:34:08 volumio-kh nmbd[610]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Nov 01 18:34:09 volumio-kh systemd[1]: systemd-rfkill.service: Succeeded. Nov 01 18:34:09 volumio-kh wireless.js[465]: Cleaning previous... Nov 01 18:34:09 volumio-kh sudo[651]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Nov 01 18:34:09 volumio-kh sudo[651]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:09 volumio-kh sudo[651]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:09 volumio-kh sudo[653]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Nov 01 18:34:09 volumio-kh sudo[653]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:09 volumio-kh ntpd[630]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Nov 01 18:34:09 volumio-kh mpd[631]: Nov 01 18:34 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 01 18:34:09 volumio-kh mpd[631]: Nov 01 18:34 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 01 18:34:09 volumio-kh mpd[631]: Nov 01 18:34 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 01 18:34:10 volumio-kh systemd[1]: Started Music Player Daemon. Nov 01 18:34:10 volumio-kh sudo[653]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:10 volumio-kh wireless.js[465]: Stopped aP Nov 01 18:34:10 volumio-kh sudo[662]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 01 18:34:10 volumio-kh sudo[662]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:10 volumio-kh sudo[662]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:10 volumio-kh kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 01 18:34:10 volumio-kh sudo[664]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Nov 01 18:34:10 volumio-kh sudo[664]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:10 volumio-kh sudo[664]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:10 volumio-kh sudo[671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 01 18:34:10 volumio-kh sudo[671]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:10 volumio-kh sudo[671]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:10 volumio-kh sudo[673]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Nov 01 18:34:10 volumio-kh sudo[673]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:10 volumio-kh ntpd[630]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Nov 01 18:34:11 volumio-kh ntpd[630]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Nov 01 18:34:12 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:12] [info] asio async_connect error: system:111 (Connection refused) Nov 01 18:34:12 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:12] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 01 18:34:12 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:12] [error] handle_connect error: Underlying Transport Error Nov 01 18:34:13 volumio-kh sudo[673]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:13 volumio-kh wireless.js[465]: Start wireless flow Nov 01 18:34:13 volumio-kh wireless.js[465]: Stopped hotspot (if there).. Nov 01 18:34:13 volumio-kh sudo[678]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Nov 01 18:34:13 volumio-kh sudo[678]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:13 volumio-kh sudo[678]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:13 volumio-kh sudo[680]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Nov 01 18:34:13 volumio-kh sudo[680]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:13 volumio-kh kernel: Bluetooth: Core ver 2.22 Nov 01 18:34:13 volumio-kh kernel: NET: Registered protocol family 31 Nov 01 18:34:13 volumio-kh kernel: Bluetooth: HCI device and connection manager initialized Nov 01 18:34:13 volumio-kh kernel: Bluetooth: HCI socket layer initialized Nov 01 18:34:13 volumio-kh kernel: Bluetooth: L2CAP socket layer initialized Nov 01 18:34:13 volumio-kh kernel: Bluetooth: SCO socket layer initialized Nov 01 18:34:13 volumio-kh btuart[470]: bcm43xx_init Nov 01 18:34:13 volumio-kh btuart[470]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd Nov 01 18:34:13 volumio-kh btuart[470]: Set Controller UART speed to 3000000 bit/s Nov 01 18:34:13 volumio-kh btuart[470]: Device setup complete Nov 01 18:34:13 volumio-kh kernel: Bluetooth: HCI UART driver ver 2.3 Nov 01 18:34:13 volumio-kh kernel: Bluetooth: HCI UART protocol H4 registered Nov 01 18:34:13 volumio-kh kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Nov 01 18:34:13 volumio-kh kernel: Bluetooth: HCI UART protocol Broadcom registered Nov 01 18:34:13 volumio-kh systemd[1]: Starting Load/Save RF Kill Switch Status... Nov 01 18:34:13 volumio-kh systemd[1]: Started Configure Bluetooth Modems connected by UART. Nov 01 18:34:13 volumio-kh systemd[1]: Started Load/Save RF Kill Switch Status. Nov 01 18:34:13 volumio-kh systemd[1]: Created slice system-bthelper.slice. Nov 01 18:34:13 volumio-kh systemd[1]: Starting Raspberry Pi bluetooth helper... Nov 01 18:34:13 volumio-kh bthelper[691]: Raspberry Pi BDADDR already set Nov 01 18:34:13 volumio-kh systemd[1]: Started Raspberry Pi bluetooth helper. Nov 01 18:34:13 volumio-kh systemd[1]: Starting Bluetooth service... Nov 01 18:34:13 volumio-kh bluetoothd[701]: Bluetooth daemon 5.50 Nov 01 18:34:13 volumio-kh bluetoothd[701]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Nov 01 18:34:13 volumio-kh systemd[1]: Started Bluetooth service. Nov 01 18:34:13 volumio-kh systemd[1]: Reached target Bluetooth. Nov 01 18:34:13 volumio-kh bluetoothd[701]: Starting SDP server Nov 01 18:34:13 volumio-kh bluetoothd[701]: Excluding (cli) sap Nov 01 18:34:13 volumio-kh kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Nov 01 18:34:13 volumio-kh kernel: Bluetooth: BNEP filters: protocol multicast Nov 01 18:34:13 volumio-kh kernel: Bluetooth: BNEP socket layer initialized Nov 01 18:34:13 volumio-kh dbus-daemon[476]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=701 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Nov 01 18:34:13 volumio-kh bluetoothd[701]: Bluetooth management interface 1.18 initialized Nov 01 18:34:13 volumio-kh systemd[1]: Starting Hostname Service... Nov 01 18:34:13 volumio-kh bluetoothd[701]: Failed to set privacy: Rejected (0x0b) Nov 01 18:34:13 volumio-kh sudo[680]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:13 volumio-kh wireless.js[465]: DHCP IP Nov 01 18:34:13 volumio-kh wireless.js[465]: Start ap Nov 01 18:34:13 volumio-kh wpa_supplicant[704]: Successfully initialized wpa_supplicant Nov 01 18:34:13 volumio-kh sudo[705]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Nov 01 18:34:13 volumio-kh sudo[705]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:13 volumio-kh kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 01 18:34:13 volumio-kh dhcpcd[706]: dev: loaded udev Nov 01 18:34:13 volumio-kh dbus-daemon[476]: [system] Successfully activated service 'org.freedesktop.hostname1' Nov 01 18:34:13 volumio-kh systemd[1]: Started Hostname Service. Nov 01 18:34:13 volumio-kh dhcpcd-run-hooks[724]: wlan0: starting wpa_supplicant Nov 01 18:34:14 volumio-kh dhcpcd-run-hooks[729]: wlan0: failed to start wpa_supplicant Nov 01 18:34:14 volumio-kh dhcpcd-run-hooks[730]: 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 Nov 01 18:34:14 volumio-kh dhcpcd[706]: wlan0: connected to Access Point `' Nov 01 18:34:14 volumio-kh dhcpcd[706]: no interfaces have a carrier Nov 01 18:34:14 volumio-kh dhcpcd[706]: forked to background, child pid 740 Nov 01 18:34:14 volumio-kh dhcpcd[740]: eth0: waiting for carrier Nov 01 18:34:14 volumio-kh dhcpcd[740]: wlan0: waiting for carrier Nov 01 18:34:14 volumio-kh sudo[705]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:14 volumio-kh wireless.js[465]: trying... Nov 01 18:34:14 volumio-kh sudo[742]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:14 volumio-kh sudo[742]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:14 volumio-kh sudo[742]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:15 volumio-kh wireless.js[465]: trying... Nov 01 18:34:15 volumio-kh sudo[745]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:15 volumio-kh sudo[745]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:15 volumio-kh sudo[745]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:16 volumio-kh wireless.js[465]: trying... Nov 01 18:34:16 volumio-kh sudo[748]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:16 volumio-kh sudo[748]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:16 volumio-kh sudo[748]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:16 volumio-kh wpa_supplicant[728]: wlan0: Trying to associate with SSID 'NETGEAR43' Nov 01 18:34:17 volumio-kh wireless.js[465]: trying... Nov 01 18:34:17 volumio-kh sudo[751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:17 volumio-kh sudo[751]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:17 volumio-kh sudo[751]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:18 volumio-kh systemd[1]: systemd-rfkill.service: Succeeded. Nov 01 18:34:18 volumio-kh bthelper[691]: Changing power off succeeded Nov 01 18:34:18 volumio-kh bthelper[691]: [CHG] Controller DC:A6:32:FA:57:A8 Powered: no Nov 01 18:34:18 volumio-kh bthelper[691]: [CHG] Controller DC:A6:32:FA:57:A8 Discovering: no Nov 01 18:34:18 volumio-kh bthelper[691]: [CHG] Controller DC:A6:32:FA:57:A8 Class: 0x00000000 Nov 01 18:34:18 volumio-kh bthelper[691]: [CHG] Controller DC:A6:32:FA:57:A8 Class: 0x0000041c Nov 01 18:34:18 volumio-kh bthelper[691]: Changing power on succeeded Nov 01 18:34:18 volumio-kh wireless.js[465]: trying... Nov 01 18:34:18 volumio-kh sudo[761]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:18 volumio-kh sudo[761]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:18 volumio-kh sudo[761]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:19 volumio-kh dhcpcd[740]: wlan0: carrier acquired Nov 01 18:34:19 volumio-kh dhcpcd[740]: wlan0: connected to Access Point `NETGEAR43' Nov 01 18:34:19 volumio-kh wpa_supplicant[728]: wlan0: Associated with 3c:37:86:b1:fb:0e Nov 01 18:34:19 volumio-kh wpa_supplicant[728]: wlan0: CTRL-EVENT-CONNECTED - Connection to 3c:37:86:b1:fb:0e completed [id=0 id_str=] Nov 01 18:34:19 volumio-kh wpa_supplicant[728]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Nov 01 18:34:19 volumio-kh dhcpcd[740]: DUID 00:01:00:01:2b:1f:b5:b8:dc:a6:32:fa:57:a6 Nov 01 18:34:19 volumio-kh dhcpcd[740]: wlan0: IAID 32:fa:57:a7 Nov 01 18:34:19 volumio-kh dhcpcd[740]: wlan0: adding address fe80::dea6:32ff:fefa:57a7 Nov 01 18:34:19 volumio-kh dhcpcd[740]: ipv6_addaddr1: Permission denied Nov 01 18:34:19 volumio-kh dhcpcd[740]: wlan0: carrier lost Nov 01 18:34:19 volumio-kh dhcpcd[740]: wlan0: carrier acquired Nov 01 18:34:19 volumio-kh dhcpcd[740]: wlan0: IAID 32:fa:57:a7 Nov 01 18:34:19 volumio-kh wireless.js[465]: trying... Nov 01 18:34:19 volumio-kh sudo[776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:19 volumio-kh sudo[776]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:19 volumio-kh sudo[776]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:19 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:19] [info] asio async_connect error: system:111 (Connection refused) Nov 01 18:34:19 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:19] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 01 18:34:19 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:19] [error] handle_connect error: Underlying Transport Error Nov 01 18:34:20 volumio-kh dhcpcd[740]: wlan0: soliciting an IPv6 router Nov 01 18:34:20 volumio-kh dhcpcd[740]: eth0: carrier acquired Nov 01 18:34:20 volumio-kh dhcpcd[421]: eth0: carrier acquired Nov 01 18:34:20 volumio-kh sh[385]: eth0: carrier acquired Nov 01 18:34:20 volumio-kh dhcpcd[740]: eth0: IAID 32:fa:57:a6 Nov 01 18:34:20 volumio-kh dhcpcd[740]: eth0: adding address fe80::dea6:32ff:fefa:57a6 Nov 01 18:34:20 volumio-kh sh[385]: DUID 00:01:00:01:2b:1f:b5:b8:dc:a6:32:fa:57:a6 Nov 01 18:34:20 volumio-kh sh[385]: eth0: IAID 32:fa:57:a6 Nov 01 18:34:20 volumio-kh sh[385]: eth0: adding address fe80::dea6:32ff:fefa:57a6 Nov 01 18:34:20 volumio-kh sh[385]: ipv6_addaddr1: Permission denied Nov 01 18:34:20 volumio-kh dhcpcd[421]: DUID 00:01:00:01:2b:1f:b5:b8:dc:a6:32:fa:57:a6 Nov 01 18:34:20 volumio-kh dhcpcd[421]: eth0: IAID 32:fa:57:a6 Nov 01 18:34:20 volumio-kh dhcpcd[421]: eth0: adding address fe80::dea6:32ff:fefa:57a6 Nov 01 18:34:20 volumio-kh dhcpcd[740]: ipv6_addaddr1: Permission denied Nov 01 18:34:20 volumio-kh dhcpcd[421]: ipv6_addaddr1: Permission denied Nov 01 18:34:20 volumio-kh kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Nov 01 18:34:20 volumio-kh dhcpcd[740]: wlan0: rebinding lease of 192.168.1.27 Nov 01 18:34:20 volumio-kh dhcpcd[740]: wlan0: probing address 192.168.1.27/24 Nov 01 18:34:20 volumio-kh sh[385]: eth0: soliciting an IPv6 router Nov 01 18:34:20 volumio-kh dhcpcd[421]: eth0: soliciting an IPv6 router Nov 01 18:34:20 volumio-kh wireless.js[465]: trying... Nov 01 18:34:20 volumio-kh sudo[781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:20 volumio-kh sudo[781]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:20 volumio-kh sudo[781]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:20 volumio-kh sh[385]: eth0: rebinding lease of 192.168.1.28 Nov 01 18:34:20 volumio-kh dhcpcd[421]: eth0: rebinding lease of 192.168.1.28 Nov 01 18:34:20 volumio-kh sh[385]: eth0: probing address 192.168.1.28/24 Nov 01 18:34:20 volumio-kh dhcpcd[421]: eth0: probing address 192.168.1.28/24 Nov 01 18:34:20 volumio-kh dhcpcd[740]: eth0: soliciting an IPv6 router Nov 01 18:34:20 volumio-kh dhcpcd[740]: eth0: rebinding lease of 192.168.1.28 Nov 01 18:34:20 volumio-kh dhcpcd[740]: eth0: probing address 192.168.1.28/24 Nov 01 18:34:21 volumio-kh ifplugd(eth0)[625]: Link beat detected. Nov 01 18:34:21 volumio-kh ifplugd(eth0)[625]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Nov 01 18:34:21 volumio-kh ifplugd(eth0)[625]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Nov 01 18:34:21 volumio-kh wireless.js[465]: trying... Nov 01 18:34:21 volumio-kh sudo[791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:21 volumio-kh sudo[791]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:21 volumio-kh sudo[791]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:21 volumio-kh kernel: cam-dummy-reg: disabling Nov 01 18:34:21 volumio-kh kernel: cam1-reg: disabling Nov 01 18:34:22 volumio-kh wireless.js[465]: trying... Nov 01 18:34:22 volumio-kh sudo[794]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:22 volumio-kh sudo[794]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:22 volumio-kh sudo[794]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:23 volumio-kh wireless.js[465]: trying... Nov 01 18:34:23 volumio-kh sudo[797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:23 volumio-kh sudo[797]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:23 volumio-kh sudo[797]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:24 volumio-kh wireless.js[465]: trying... Nov 01 18:34:24 volumio-kh sudo[800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:24 volumio-kh sudo[800]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:24 volumio-kh sudo[800]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:25 volumio-kh wireless.js[465]: trying... Nov 01 18:34:25 volumio-kh sudo[803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:25 volumio-kh sudo[803]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:25 volumio-kh sudo[803]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:25 volumio-kh dhcpcd[740]: wlan0: leased 192.168.1.27 for 86400 seconds Nov 01 18:34:25 volumio-kh avahi-daemon[482]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.27. Nov 01 18:34:25 volumio-kh dhcpcd[740]: wlan0: adding route to 192.168.1.0/24 Nov 01 18:34:25 volumio-kh dhcpcd[740]: wlan0: adding default route via 192.168.1.1 Nov 01 18:34:25 volumio-kh avahi-daemon[482]: New relevant interface wlan0.IPv4 for mDNS. Nov 01 18:34:25 volumio-kh avahi-daemon[482]: Registering new address record for 192.168.1.27 on wlan0.IPv4. Nov 01 18:34:25 volumio-kh dhcpcd[740]: eth0: leased 192.168.1.28 for 86400 seconds Nov 01 18:34:25 volumio-kh avahi-daemon[482]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.28. Nov 01 18:34:25 volumio-kh avahi-daemon[482]: New relevant interface eth0.IPv4 for mDNS. Nov 01 18:34:25 volumio-kh avahi-daemon[482]: Registering new address record for 192.168.1.28 on eth0.IPv4. Nov 01 18:34:25 volumio-kh dhcpcd[740]: eth0: adding route to 192.168.1.0/24 Nov 01 18:34:25 volumio-kh dhcpcd[740]: eth0: adding default route via 192.168.1.1 Nov 01 18:34:26 volumio-kh sh[385]: eth0: leased 192.168.1.28 for 86400 seconds Nov 01 18:34:26 volumio-kh dhcpcd[421]: eth0: leased 192.168.1.28 for 86400 seconds Nov 01 18:34:26 volumio-kh sh[385]: eth0: adding route to 192.168.1.0/24 Nov 01 18:34:26 volumio-kh sh[385]: eth0: adding default route via 192.168.1.1 Nov 01 18:34:26 volumio-kh dhcpcd[421]: eth0: adding route to 192.168.1.0/24 Nov 01 18:34:26 volumio-kh dhcpcd[421]: eth0: adding default route via 192.168.1.1 Nov 01 18:34:26 volumio-kh sh[385]: forked to background, child pid 865 Nov 01 18:34:26 volumio-kh dhcpcd[421]: forked to background, child pid 865 Nov 01 18:34:26 volumio-kh ifplugd(eth0)[625]: client: ifup: interface eth0 already configured Nov 01 18:34:26 volumio-kh sh[385]: eth0=eth0 Nov 01 18:34:26 volumio-kh ifplugd(eth0)[625]: Program executed successfully. Nov 01 18:34:26 volumio-kh wireless.js[465]: trying... Nov 01 18:34:26 volumio-kh sudo[892]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 01 18:34:26 volumio-kh sudo[892]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:26 volumio-kh sudo[892]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:26 volumio-kh wireless.js[465]: Connected to: ----NETGEAR43 Nov 01 18:34:26 volumio-kh wireless.js[465]: ---- Nov 01 18:34:26 volumio-kh sudo[895]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 18:34:26 volumio-kh sudo[895]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:26 volumio-kh sudo[895]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:26 volumio-kh wireless.js[465]: ... joined AP, wlan0 IPv4 is 192.168.1.27, ipV6 is undefined Nov 01 18:34:26 volumio-kh wireless.js[465]: It's done! AP Nov 01 18:34:26 volumio-kh systemd[1]: Started Wireless Services. Nov 01 18:34:26 volumio-kh systemd[1]: Started Volumio Backend Module. Nov 01 18:34:26 volumio-kh kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 01 18:34:27 volumio-kh ntpd[630]: Listen normally on 3 eth0 192.168.1.28:123 Nov 01 18:34:27 volumio-kh ntpd[630]: Listen normally on 4 wlan0 192.168.1.27:123 Nov 01 18:34:27 volumio-kh ntpd[630]: new interface(s) found: waking up resolver Nov 01 18:34:28 volumio-kh volumio[900]: info: ------------------------------------------- Nov 01 18:34:28 volumio-kh volumio[900]: info: ----- Volumio3 ---- Nov 01 18:34:28 volumio-kh volumio[900]: info: ------------------------------------------- Nov 01 18:34:28 volumio-kh volumio[900]: info: ----- System startup ---- Nov 01 18:34:28 volumio-kh volumio[900]: info: ------------------------------------------- Nov 01 18:34:28 volumio-kh systemd[1]: Started Samba NMB Daemon. Nov 01 18:34:28 volumio-kh systemd[1]: Starting Samba Winbind Daemon... Nov 01 18:34:28 volumio-kh nmbd[610]: [2023/11/01 18:34:28.839856, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 01 18:34:28 volumio-kh nmbd[610]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Nov 01 18:34:29 volumio-kh winbindd[915]: [2023/11/01 18:34:29.053052, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Nov 01 18:34:29 volumio-kh winbindd[915]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Nov 01 18:34:29 volumio-kh winbindd[915]: [2023/11/01 18:34:29.068969, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 01 18:34:29 volumio-kh systemd[1]: Started Samba Winbind Daemon. Nov 01 18:34:29 volumio-kh winbindd[915]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Nov 01 18:34:29 volumio-kh systemd[1]: Starting Samba SMB Daemon... Nov 01 18:34:29 volumio-kh volumio[900]: info: MYVOLUMIO Environment detected Nov 01 18:34:29 volumio-kh winbindd[915]: [2023/11/01 18:34:29.448926, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Nov 01 18:34:29 volumio-kh winbindd[915]: res_names->count = 1, expected 2 Nov 01 18:34:29 volumio-kh smbd[920]: [2023/11/01 18:34:29.471341, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 01 18:34:29 volumio-kh volumio[900]: info: Plugin folders cleanup Nov 01 18:34:29 volumio-kh volumio[900]: info: Scanning into folder /volumio/app/plugins/ Nov 01 18:34:29 volumio-kh volumio[900]: info: Scanning category audio_interface Nov 01 18:34:29 volumio-kh volumio[900]: info: Scanning category miscellanea Nov 01 18:34:29 volumio-kh volumio[900]: info: Scanning category music_service Nov 01 18:34:29 volumio-kh volumio[900]: info: Scanning category plugins.json Nov 01 18:34:29 volumio-kh volumio[900]: info: Scanning category system_controller Nov 01 18:34:29 volumio-kh systemd[1]: Started Samba SMB Daemon. Nov 01 18:34:29 volumio-kh smbd[920]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Nov 01 18:34:29 volumio-kh systemd[1]: Reached target Multi-User System. Nov 01 18:34:29 volumio-kh volumio[900]: info: Scanning category user_interface Nov 01 18:34:29 volumio-kh systemd[1]: Reached target Graphical Interface. Nov 01 18:34:29 volumio-kh systemd[1]: Starting Update UTMP about System Runlevel Changes... Nov 01 18:34:29 volumio-kh volumio[900]: info: Scanning into folder /data/plugins/ Nov 01 18:34:29 volumio-kh volumio[900]: info: Plugin folders cleanup completed Nov 01 18:34:29 volumio-kh volumio[900]: info: ------------------------------------------- Nov 01 18:34:29 volumio-kh volumio[900]: info: ----- Core plugins startup ---- Nov 01 18:34:29 volumio-kh volumio[900]: info: ------------------------------------------- Nov 01 18:34:29 volumio-kh volumio[900]: info: Loading plugins from folder /volumio/app/plugins/ Nov 01 18:34:29 volumio-kh volumio[900]: info: Adding plugin upnp to MyMusic Plugins Nov 01 18:34:29 volumio-kh volumio[900]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 01 18:34:29 volumio-kh volumio[900]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 01 18:34:29 volumio-kh volumio[900]: info: Loading plugins from folder /data/plugins/ Nov 01 18:34:29 volumio-kh volumio[900]: info: Loading plugin "system"... Nov 01 18:34:29 volumio-kh systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Nov 01 18:34:29 volumio-kh systemd[1]: Started Update UTMP about System Runlevel Changes. Nov 01 18:34:29 volumio-kh systemd[1]: Startup finished in 9.739s (kernel) + 31.035s (userspace) = 40.775s. Nov 01 18:34:29 volumio-kh volumio[900]: info: Loading plugin "appearance"... Nov 01 18:34:29 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:29] [connect] Successful connection Nov 01 18:34:30 volumio-kh volumio[900]: info: Loading plugin "network"... Nov 01 18:34:30 volumio-kh volumio[900]: info: Refreshing Cached IP Addresses Nov 01 18:34:30 volumio-kh sudo[932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 18:34:30 volumio-kh sudo[932]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:30 volumio-kh sudo[932]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:30 volumio-kh sudo[934]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 18:34:30 volumio-kh sudo[934]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:30 volumio-kh volumio[900]: info: Loading plugin "services"... Nov 01 18:34:30 volumio-kh volumio[900]: info: Loading plugin "alsa_controller"... Nov 01 18:34:30 volumio-kh sudo[934]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:30 volumio-kh sudo[937]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 01 18:34:30 volumio-kh sudo[937]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:30 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:34:30 volumio-kh volumio[900]: info: Loading plugin "wizard"... Nov 01 18:34:30 volumio-kh volumio[900]: info: Loading plugin "volumio_command_line_client"... Nov 01 18:34:30 volumio-kh volumio[900]: info: Loading plugin "upnp"... Nov 01 18:34:30 volumio-kh volumio[900]: info: [1698834870616] Starting Upmpd Daemon Nov 01 18:34:30 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:34:30 volumio-kh volumio[900]: info: Loading plugin "my_music"... Nov 01 18:34:30 volumio-kh volumio[900]: info: Loading plugin "mpd"... Nov 01 18:34:30 volumio-kh volumio[900]: info: Creating MPD Configuration file Nov 01 18:34:30 volumio-kh volumio[900]: info: Loading plugin "upnp_browser"... Nov 01 18:34:30 volumio-kh sudo[943]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:34:30 volumio-kh sudo[943]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:30 volumio-kh sudo[943]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:30 volumio-kh sudo[945]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:34:30 volumio-kh sudo[945]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:30 volumio-kh systemd[1]: Stopping Music Player Daemon... Nov 01 18:34:31 volumio-kh systemd[1]: mpd.service: Succeeded. Nov 01 18:34:31 volumio-kh systemd[1]: Stopped Music Player Daemon. Nov 01 18:34:31 volumio-kh systemd[1]: Starting Music Player Daemon... Nov 01 18:34:31 volumio-kh volumio[900]: info: Loading plugin "networkfs"... Nov 01 18:34:31 volumio-kh volumio[900]: info: Starting Udev Watcher for removable devices Nov 01 18:34:31 volumio-kh sudo[953]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Qnapchiu2022,password=Hxtpc-001,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.209/Multimedia /mnt/NAS/Volumio Nov 01 18:34:31 volumio-kh sudo[953]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:31 volumio-kh kernel: FS-Cache: Netfs 'cifs' registered for caching Nov 01 18:34:31 volumio-kh kernel: Key type cifs.spnego registered Nov 01 18:34:31 volumio-kh kernel: Key type cifs.idmap registered Nov 01 18:34:31 volumio-kh kernel: CIFS: Attempting to mount //192.168.1.209/Multimedia Nov 01 18:34:31 volumio-kh 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. Nov 01 18:34:31 volumio-kh mpd[950]: Nov 01 18:34 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 01 18:34:31 volumio-kh mpd[950]: Nov 01 18:34 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 01 18:34:31 volumio-kh mpd[950]: Nov 01 18:34 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 01 18:34:31 volumio-kh systemd[1]: Started Music Player Daemon. Nov 01 18:34:31 volumio-kh sudo[945]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:31 volumio-kh volumio[900]: info: Ignoring mount for partition: boot Nov 01 18:34:31 volumio-kh volumio[900]: info: Ignoring mount for partition: volumio Nov 01 18:34:31 volumio-kh volumio[900]: info: Ignoring mount for partition: volumio_data Nov 01 18:34:31 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:34:31 volumio-kh volumio[900]: info: Loading plugin "alarm-clock"... Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "airplay_emulation"... Nov 01 18:34:32 volumio-kh volumio[900]: info: Starting Shairport Sync Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "last_100"... Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "webradio"... Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "i2s_dacs"... Nov 01 18:34:32 volumio-kh volumio[900]: info: I2S DAC not set, start Auto-detection Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "volumiodiscovery"... Nov 01 18:34:32 volumio-kh volumio[900]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:34:32 volumio-kh node[900]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 01 18:34:32 volumio-kh volumio[900]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:34:32 volumio-kh node[900]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:34:32 volumio-kh volumio[900]: *** WARNING *** For more information see Nov 01 18:34:32 volumio-kh node[900]: *** WARNING *** For more information see Nov 01 18:34:32 volumio-kh volumio[900]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:34:32 volumio-kh node[900]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 01 18:34:32 volumio-kh volumio[900]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:34:32 volumio-kh node[900]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 01 18:34:32 volumio-kh volumio[900]: *** WARNING *** For more information see Nov 01 18:34:32 volumio-kh node[900]: *** WARNING *** For more information see Nov 01 18:34:32 volumio-kh volumio[900]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 01 18:34:32 volumio-kh volumio[900]: info: Discovery: Started advertising with name: Volumio-kh Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "outputs"... Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "albumart"... Nov 01 18:34:32 volumio-kh volumio[900]: info: Plugin example_plugin is not enabled Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "inputs"... Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "updater_comm"... Nov 01 18:34:32 volumio-kh volumio[900]: info: Plugin mpdemulation is not enabled Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "rest_api"... Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading plugin "websocket"... Nov 01 18:34:32 volumio-kh volumio[900]: info: Loading i18n strings for locale en Nov 01 18:34:32 volumio-kh volumio[900]: Updating browse sources language Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:34:32 volumio-kh volumio[900]: Forking 3 albumart workers Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::initPlayerControls Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: Express server listening on port 3000 Nov 01 18:34:32 volumio-kh volumio[900]: [Metrics] WebUI: 4s 875.09ms Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreStateMachine::resetVolumioState Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreStateMachine::getcurrentVolume Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreStateMachine::pushState Nov 01 18:34:32 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::volumioPushState Nov 01 18:34:32 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:34:32 volumio-kh volumio[900]: info: MPD Permissions set Nov 01 18:34:32 volumio-kh volumio-remote-updater[463]: [2023-11-01 18:34:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1698834869 101 Nov 01 18:34:32 volumio-kh volumio[900]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Nov 01 18:34:32 volumio-kh volumio[900]: info: MPD running with PID950 Nov 01 18:34:32 volumio-kh volumio[900]: ,establishing connection Nov 01 18:34:33 volumio-kh volumio[900]: info: Reloading queue from file Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:33 volumio-kh volumio[900]: error: updateQueue error: null Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreStateMachine::setRepeat true single undefined Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreStateMachine::pushState Nov 01 18:34:33 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::volumioPushState Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreStateMachine::setRandom null Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreStateMachine::pushState Nov 01 18:34:33 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::volumioPushState Nov 01 18:34:33 volumio-kh volumio[900]: info: Setting Device type: Raspberry PI Nov 01 18:34:33 volumio-kh volumio[900]: error: updateQueue error: null Nov 01 18:34:33 volumio-kh volumio[900]: Starting albumart workers Nov 01 18:34:33 volumio-kh volumio[900]: Starting albumart workers Nov 01 18:34:33 volumio-kh volumio[900]: Starting albumart workers Nov 01 18:34:33 volumio-kh volumio[900]: info: Discovery: adding 8502fdec-04e2-4236-8c15-6976db348c7f Nov 01 18:34:33 volumio-kh volumio[900]: info: Discovery: Found device Volumio-kh Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:33 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:33 volumio-kh volumio[900]: info: Discovery: this is already registered, 8502fdec-04e2-4236-8c15-6976db348c7f Nov 01 18:34:33 volumio-kh volumio[900]: info: Discovery: Found device Volumio-kh Nov 01 18:34:33 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:33 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:34 volumio-kh systemd[1]: systemd-fsckd.service: Succeeded. Nov 01 18:34:34 volumio-kh sudo[937]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 18:34:37 volumio-kh volumio[900]: info: Discovery: Getting this device information Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:37 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 18:34:37 volumio-kh volumio[900]: info: Discovery: Getting this device information Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:37 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 18:34:37 volumio-kh volumio[900]: verbose: New Socket.io Connection to 192.168.1.28:3000 from 192.168.1.32 UA: Dart/3.5 (dart:io) Total Clients: 2 Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:37 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 01 18:34:37 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 01 18:34:37 volumio-kh volumio[900]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 01 18:34:38 volumio-kh sudo[953]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:38 volumio-kh volumio[900]: info: Cannot mount NAS Volumio at system boot, trial number 1 ,retrying in 5 seconds Nov 01 18:34:38 volumio-kh volumio[900]: info: Completed loading Core Plugins Nov 01 18:34:38 volumio-kh volumio[900]: info: Preparing to generate the ALSA configuration file Nov 01 18:34:38 volumio-kh kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Nov 01 18:34:38 volumio-kh kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Nov 01 18:34:38 volumio-kh volumio[900]: info: Asound.conf file unchanged, so no further update is needed Nov 01 18:34:38 volumio-kh volumio[900]: info: Output device has changed, restarting MPD Nov 01 18:34:38 volumio-kh sudo[1037]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 18:34:38 volumio-kh sudo[1037]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:38 volumio-kh volumio[900]: info: Output device has changed, restarting Shairport Sync Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:34:38 volumio-kh sudo[1037]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:38 volumio-kh sudo[1039]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 18:34:38 volumio-kh sudo[1039]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:38 volumio-kh systemd[1]: Stopping Music Player Daemon... Nov 01 18:34:38 volumio-kh volumio[900]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:34:38 volumio-kh volumio[900]: info: ___________ START PLUGINS ___________ Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:34:38 volumio-kh volumio[900]: info: [1698834878109] CoreMusicLibrary::Adding element Media Servers Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:34:38 volumio-kh systemd[1]: mpd.service: Succeeded. Nov 01 18:34:38 volumio-kh systemd[1]: Stopped Music Player Daemon. Nov 01 18:34:38 volumio-kh systemd[1]: Starting Music Player Daemon... Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:34:38 volumio-kh volumio[900]: info: [1698834878209] CoreMusicLibrary::Adding element Last_100 Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 18:34:38 volumio-kh volumio[900]: info: [1698834878211] CoreMusicLibrary::Adding element Webradio Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:34:38 volumio-kh volumio[900]: info: Volumio Calling Home Nov 01 18:34:38 volumio-kh volumio[900]: info: Completed starting Core Plugins Nov 01 18:34:38 volumio-kh volumio[900]: info: ------------------------------------------- Nov 01 18:34:38 volumio-kh volumio[900]: info: ----- MyVolumio plugins startup ---- Nov 01 18:34:38 volumio-kh volumio[900]: info: ------------------------------------------- Nov 01 18:34:38 volumio-kh volumio[900]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 01 18:34:38 volumio-kh volumio[900]: info: MPD Permissions set Nov 01 18:34:38 volumio-kh volumio[900]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:38 volumio-kh volumio[900]: info: Starting Shairport Sync Nov 01 18:34:38 volumio-kh volumio[900]: info: Starting Shairport Sync Nov 01 18:34:38 volumio-kh sudo[1062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 18:34:38 volumio-kh volumio[900]: info: Starting Shairport Sync Nov 01 18:34:38 volumio-kh sudo[1062]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:38 volumio-kh sudo[1064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 18:34:38 volumio-kh systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 01 18:34:38 volumio-kh systemd[1]: shairport-sync.service: Succeeded. Nov 01 18:34:38 volumio-kh sudo[1064]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:38 volumio-kh systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 01 18:34:38 volumio-kh systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 01 18:34:38 volumio-kh sudo[1062]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:38 volumio-kh systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 01 18:34:38 volumio-kh systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Nov 01 18:34:38 volumio-kh systemd[1]: shairport-sync.service: Succeeded. Nov 01 18:34:38 volumio-kh systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 01 18:34:38 volumio-kh sudo[1068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 18:34:38 volumio-kh systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 01 18:34:38 volumio-kh sudo[1064]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:38 volumio-kh sudo[1068]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:38 volumio-kh volumio[900]: info: Shairport-Sync Started Nov 01 18:34:38 volumio-kh volumio[900]: Error adding Membership: Error: addMembership EINVAL Nov 01 18:34:38 volumio-kh volumio[900]: info: Shairport-Sync Started Nov 01 18:34:38 volumio-kh systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 01 18:34:38 volumio-kh systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Nov 01 18:34:38 volumio-kh systemd[1]: shairport-sync.service: Succeeded. Nov 01 18:34:38 volumio-kh systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 01 18:34:38 volumio-kh systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 01 18:34:38 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:38 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:38 volumio-kh sudo[1068]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:38 volumio-kh volumio[900]: info: Shairport-Sync Started Nov 01 18:34:38 volumio-kh volumio[900]: info: Volumio called home Nov 01 18:34:38 volumio-kh mpd[1055]: Nov 01 18:34 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 01 18:34:38 volumio-kh mpd[1055]: Nov 01 18:34 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 01 18:34:38 volumio-kh mpd[1055]: Nov 01 18:34 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 01 18:34:38 volumio-kh systemd[1]: Started Music Player Daemon. Nov 01 18:34:38 volumio-kh sudo[1039]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:38 volumio-kh volumio[900]: error: updateQueue error: null Nov 01 18:34:39 volumio-kh sudo[1078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 18:34:39 volumio-kh sudo[1078]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:39 volumio-kh sudo[1078]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:39 volumio-kh sudo[1080]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 18:34:39 volumio-kh sudo[1080]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:39 volumio-kh sudo[1080]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:39 volumio-kh volumio[900]: verbose: New Socket.io Connection to 192.168.1.28 from 192.168.1.32 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_2_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 4 Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 01 18:34:39 volumio-kh sudo[1084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 18:34:39 volumio-kh sudo[1084]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:39 volumio-kh sudo[1084]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:39 volumio-kh sudo[1086]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 18:34:39 volumio-kh sudo[1086]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:39 volumio-kh sudo[1086]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:39 volumio-kh volumio[900]: verbose: New Socket.io Connection to 192.168.1.28 from 192.168.1.32 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_2_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 5 Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetVisibleSources Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:39 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetQueue Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreStateMachine::getQueue Nov 01 18:34:39 volumio-kh volumio[900]: info: CorePlayQueue::getQueue Nov 01 18:34:39 volumio-kh volumio[900]: info: Listing playlists Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 01 18:34:39 volumio-kh volumio[900]: info: Received Get System Info Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 18:34:39 volumio-kh volumio[900]: info: Discovery: Getting this device information Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:39 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:39 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 01 18:34:39 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 01 18:34:40 volumio-kh sudo[1090]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 18:34:40 volumio-kh sudo[1090]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:40 volumio-kh sudo[1090]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:40 volumio-kh sudo[1092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 18:34:40 volumio-kh sudo[1092]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:40 volumio-kh sudo[1092]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:40 volumio-kh sudo[1096]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 01 18:34:40 volumio-kh sudo[1096]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:40 volumio-kh systemd[1]: Started UPnP Renderer front-end to MPD. Nov 01 18:34:40 volumio-kh sudo[1096]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:40 volumio-kh volumio[900]: info: Upmpdcli Daemon Started Nov 01 18:34:40 volumio-kh volumio[1098]: Generating RSA private key, 4096 bit long modulus (2 primes) Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 01 18:34:41 volumio-kh volumio[900]: info: Received Get System Info Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 18:34:41 volumio-kh volumio[900]: info: Discovery: Getting this device information Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:41 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 18:34:41 volumio-kh volumio[900]: info: Discovery: Getting this device information Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:41 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 18:34:41 volumio-kh volumio[900]: info: Discovery: Getting this device information Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:41 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:41 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 18:34:43 volumio-kh sudo[1115]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Qnapchiu2022,password=Hxtpc-001,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.209/Multimedia /mnt/NAS/Volumio Nov 01 18:34:43 volumio-kh sudo[1115]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:43 volumio-kh kernel: CIFS: Attempting to mount //192.168.1.209/Multimedia Nov 01 18:34:43 volumio-kh systemd[1]: systemd-hostnamed.service: Succeeded. Nov 01 18:34:49 volumio-kh sudo[1115]: pam_unix(sudo:session): session closed for user root Nov 01 18:34:49 volumio-kh volumio[900]: info: Cannot mount NAS Volumio at system boot, trial number 2 ,retrying in 5 seconds Nov 01 18:34:49 volumio-kh kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Nov 01 18:34:49 volumio-kh kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Nov 01 18:34:49 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 01 18:34:49 volumio-kh volumio[900]: info: Received Get System Info Nov 01 18:34:49 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 18:34:49 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 18:34:49 volumio-kh volumio[900]: info: Discovery: Getting this device information Nov 01 18:34:49 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:49 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:49 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 18:34:49 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Nov 01 18:34:50 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 01 18:34:50 volumio-kh volumio[900]: info: Preload queue cleared Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i7667 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i7729 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i10008 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i5655 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i3652 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i7873 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i10168 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i5442 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9098 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i11414 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9250 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9881 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9884 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i11535 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i11803 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i10779 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i4061 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i10875 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i6116 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i10790 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i6383 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9616 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9911 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i7951 Nov 01 18:34:50 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i3602 Nov 01 18:34:50 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i7667 in service upnp_browser Nov 01 18:34:50 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i7729 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i10008 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i5655 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i3652 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i7873 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/none.svg' Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i10168 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i5442 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9098 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i11414 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9250 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9881 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9884 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i11535 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i11803 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i10779 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i4061 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i10875 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i6116 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i10790 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i6383 in service upnp_browser Nov 01 18:34:51 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9616 in service upnp_browser Nov 01 18:34:52 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i9911 in service upnp_browser Nov 01 18:34:52 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i7951 in service upnp_browser Nov 01 18:34:52 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f502$*i3602 in service upnp_browser Nov 01 18:34:54 volumio-kh sudo[1122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Qnapchiu2022,password=Hxtpc-001,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.209/Multimedia /mnt/NAS/Volumio Nov 01 18:34:54 volumio-kh sudo[1122]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:34:54 volumio-kh kernel: CIFS: Attempting to mount //192.168.1.209/Multimedia Nov 01 18:34:58 volumio-kh volumio[900]: error: MyVolumio Plugin failed to start in a timely fashion Nov 01 18:34:58 volumio-kh volumio[900]: info: BOOT COMPLETED Nov 01 18:34:58 volumio-kh volumio[900]: [Metrics] CommandRouter: 29s 798.59ms Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::volumiosetStartupVolume Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::Close All Modals sent Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 01 18:34:58 volumio-kh volumio[900]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Nov 01 18:34:58 volumio-kh volumio[900]: info: Received Get System Version Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:34:58 volumio-kh volumio[900]: info: Received Get System Info Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 18:34:58 volumio-kh volumio[900]: info: Discovery: Getting this device information Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:34:58 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:34:58 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 18:34:59 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 01 18:34:59 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 01 18:34:59 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 01 18:35:00 volumio-kh sudo[1122]: pam_unix(sudo:session): session closed for user root Nov 01 18:35:00 volumio-kh volumio[900]: info: Cannot mount NAS Volumio at system boot, trial number 3 ,retrying in 5 seconds Nov 01 18:35:00 volumio-kh kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Nov 01 18:35:00 volumio-kh kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Nov 01 18:35:01 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 01 18:35:01 volumio-kh volumio[900]: info: Preload queue cleared Nov 01 18:35:05 volumio-kh sudo[1131]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Qnapchiu2022,password=Hxtpc-001,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.209/Multimedia /mnt/NAS/Volumio Nov 01 18:35:05 volumio-kh sudo[1131]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:35:05 volumio-kh kernel: CIFS: Attempting to mount //192.168.1.209/Multimedia Nov 01 18:35:06 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 18:35:06 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 18:35:06 volumio-kh volumio[900]: info: Discovery: Getting this device information Nov 01 18:35:06 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetState Nov 01 18:35:06 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:35:06 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 18:35:06 volumio-kh volumio[1098]: ................................................................................................................................................................................................................................................................................................++++ Nov 01 18:35:07 volumio-kh volumio[1098]: ......++++ Nov 01 18:35:07 volumio-kh volumio[1098]: e is 65537 (0x010001) Nov 01 18:35:07 volumio-kh volumio[1098]: writing RSA key Nov 01 18:35:08 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:35:08 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:35:08 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 01 18:35:08 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 01 18:35:08 volumio-kh volumio[900]: info: Preload queue cleared Nov 01 18:35:10 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 01 18:35:11 volumio-kh volumio[900]: info: Preload queue cleared Nov 01 18:35:11 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i8404 Nov 01 18:35:11 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i9852 Nov 01 18:35:11 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i7663 Nov 01 18:35:11 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i9509 Nov 01 18:35:11 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i7489 Nov 01 18:35:11 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i9682 Nov 01 18:35:11 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i7572 Nov 01 18:35:11 volumio-kh volumio[900]: info: Preloading song: upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i4317 Nov 01 18:35:11 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i8404 in service upnp_browser Nov 01 18:35:11 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i9852 in service upnp_browser Nov 01 18:35:11 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i7663 in service upnp_browser Nov 01 18:35:11 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i9509 in service upnp_browser Nov 01 18:35:11 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i7489 in service upnp_browser Nov 01 18:35:11 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i9682 in service upnp_browser Nov 01 18:35:11 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i7572 in service upnp_browser Nov 01 18:35:11 volumio-kh volumio[900]: info: Exploding uri upnp/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124$*i4317 in service upnp_browser Nov 01 18:35:11 volumio-kh sudo[1131]: pam_unix(sudo:session): session closed for user root Nov 01 18:35:11 volumio-kh volumio[900]: info: Cannot mount NAS Volumio at system boot, trial number 4 ,retrying in 5 seconds Nov 01 18:35:11 volumio-kh kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Nov 01 18:35:11 volumio-kh kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Nov 01 18:35:13 volumio-kh ntpd[630]: Soliciting pool server 162.159.200.123 Nov 01 18:35:14 volumio-kh ntpd[630]: Soliciting pool server 162.159.200.1 Nov 01 18:35:15 volumio-kh volumio[900]: info: Preload queue cleared Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::ClearQueue Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::stop Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:35:15 volumio-kh volumio[900]: info: CorePlayQueue::clearPlayQueue Nov 01 18:35:15 volumio-kh volumio[900]: info: CorePlayQueue::saveQueue Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::addQueueItems Nov 01 18:35:15 volumio-kh volumio[900]: info: CorePlayQueue::addQueueItems Nov 01 18:35:15 volumio-kh volumio[900]: info: Preload queue cleared Nov 01 18:35:15 volumio-kh volumio[900]: info: Adding Item to queue: upnp/folder/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124 Nov 01 18:35:15 volumio-kh volumio[900]: info: Exploding uri upnp/folder/http://192.168.1.17:9791/9b2db295-8ffa-4aaf-8fa5-0154f50cbcb6/upnp.org-ContentDirectory-1/control@0$folders$f2$f123$f124 in service upnp_browser Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:35:15 volumio-kh volumio[900]: info: CorePlayQueue::saveQueue Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::updateTrackBlock Nov 01 18:35:15 volumio-kh volumio[900]: info: CorePlayQueue::getTrackBlock Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreCommandRouter::volumioPlay Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::play index 0 Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::stop Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::play index undefined Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:35:15 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::startPlaybackTimer Nov 01 18:35:15 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:35:15 volumio-kh volumio[900]: info: [1698834915853] ControllerUPNPBrowser::clearAddPlayTrack Nov 01 18:35:15 volumio-kh volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Nov 01 18:35:15 volumio-kh volumio[900]: info: sendMpdCommand stop took 2 milliseconds Nov 01 18:35:15 volumio-kh volumio[900]: verbose: ControllerMpd::sendMpdCommand clear Nov 01 18:35:15 volumio-kh volumio[900]: info: Nov 01 18:35:15 volumio-kh volumio[900]: ---------------------------- MPD announces system playlist update Nov 01 18:35:15 volumio-kh volumio[900]: info: Ignoring MPD Status Update Nov 01 18:35:15 volumio-kh volumio[900]: info: sendMpdCommand clear took 4 milliseconds Nov 01 18:35:15 volumio-kh volumio[900]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.17:9790/minimserver/*/Multimedia/Music/Ritchie*20Blackmore*27s*20Rainbow/Live*20In*20Birmingham*202016*20*5bDisc*201*5d/1-01*20Over*20The*20Rainbow*20_*20Highway*20Star.mp3" Nov 01 18:35:15 volumio-kh volumio[900]: error: updateQueue error: null Nov 01 18:35:15 volumio-kh volumio[900]: info: ------------------------------ 5ms Nov 01 18:35:15 volumio-kh volumio[900]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.17:9790/minimserver/*/Multimedia/Music/Ritchie*20Blackmore*27s*20Rainbow/Live*20In*20Birmingham*202016*20*5bDisc*201*5d/1-01*20Over*20The*20Rainbow*20_*20Highway*20Star.mp3" Nov 01 18:35:15 volumio-kh volumio[900]: info: Nov 01 18:35:15 volumio-kh volumio[900]: ---------------------------- MPD announces system playlist update Nov 01 18:35:15 volumio-kh volumio[900]: info: Ignoring MPD Status Update Nov 01 18:35:15 volumio-kh volumio[900]: info: sendMpdCommand add "http://192.168.1.17:9790/minimserver/*/Multimedia/Music/Ritchie*20Blackmore*27s*20Rainbow/Live*20In*20Birmingham*202016*20*5bDisc*201*5d/1-01*20Over*20The*20Rainbow*20_*20Highway*20Star.mp3" took 2 milliseconds Nov 01 18:35:15 volumio-kh volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 18:35:15 volumio-kh volumio[900]: verbose: ControllerMpd::sendMpdCommand play Nov 01 18:35:15 volumio-kh volumio[900]: info: ------------------------------ 4ms Nov 01 18:35:15 volumio-kh volumio[900]: info: sendMpdCommand play took 3 milliseconds Nov 01 18:35:15 volumio-kh volumio[900]: info: Nov 01 18:35:15 volumio-kh volumio[900]: ---------------------------- MPD announces state update: player Nov 01 18:35:15 volumio-kh volumio[900]: info: ControllerMpd::getState Nov 01 18:35:15 volumio-kh volumio[900]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:35:16 volumio-kh volumio[900]: info: Nov 01 18:35:16 volumio-kh volumio[900]: ---------------------------- MPD announces system playlist update Nov 01 18:35:16 volumio-kh volumio[900]: info: Ignoring MPD Status Update Nov 01 18:35:16 volumio-kh volumio[900]: info: Nov 01 18:35:16 volumio-kh volumio[900]: ---------------------------- MPD announces state update: player Nov 01 18:35:16 volumio-kh volumio[900]: info: sendMpdCommand status took 197 milliseconds Nov 01 18:35:16 volumio-kh volumio[900]: info: ControllerMpd::getState Nov 01 18:35:16 volumio-kh volumio[900]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:35:16 volumio-kh volumio[900]: verbose: ControllerMpd::parseState Nov 01 18:35:16 volumio-kh volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:35:16 volumio-kh volumio[900]: info: ------------------------------ 42ms Nov 01 18:35:16 volumio-kh volumio[900]: info: sendMpdCommand status took 3 milliseconds Nov 01 18:35:16 volumio-kh volumio[900]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 01 18:35:16 volumio-kh volumio[900]: verbose: ControllerMpd::parseState Nov 01 18:35:16 volumio-kh volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:35:16 volumio-kh volumio[900]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:35:16 volumio-kh volumio[900]: info: ControllerMpd::pushState Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreCommandRouter::servicePushState Nov 01 18:35:16 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:35:16 volumio-kh volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":436,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Over The Rainbow / Highway Star","artist":"Ritchie Blackmore's Rainbow","album":"Live In Birmingham 2016 [Disc 1]","uri":"http://192.168.1.17:9790/minimserver/*/Multimedia/Music/Ritchie*20Blackmore*27s*20Rainbow/Live*20In*20Birmingham*202016*20*5bDisc*201*5d/1-01*20Over*20The*20Rainbow*20_*20Highway*20Star.mp3","trackType":"mp3"} Nov 01 18:35:16 volumio-kh volumio[900]: verbose: CURRENT POSITION 0 Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreStateMachine::syncState stateService play Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreStateMachine::syncState currentStatus stop Nov 01 18:35:16 volumio-kh volumio[900]: info: ------------------------------ 226ms Nov 01 18:35:16 volumio-kh volumio[900]: info: sendMpdCommand playlistinfo took 6 milliseconds Nov 01 18:35:16 volumio-kh volumio[900]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:35:16 volumio-kh volumio[900]: info: ControllerMpd::pushState Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreCommandRouter::servicePushState Nov 01 18:35:16 volumio-kh volumio[900]: info: CorePlayQueue::getTrack 0 Nov 01 18:35:16 volumio-kh volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1005,"duration":436,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Over The Rainbow / Highway Star","artist":"Ritchie Blackmore's Rainbow","album":"Live In Birmingham 2016 [Disc 1]","uri":"http://192.168.1.17:9790/minimserver/*/Multimedia/Music/Ritchie*20Blackmore*27s*20Rainbow/Live*20In*20Birmingham*202016*20*5bDisc*201*5d/1-01*20Over*20The*20Rainbow*20_*20Highway*20Star.mp3","trackType":"mp3"} Nov 01 18:35:16 volumio-kh volumio[900]: verbose: CURRENT POSITION 0 Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreStateMachine::syncState stateService play Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:35:16 volumio-kh volumio[900]: info: Received an update from plugin. extracting info from payload Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreStateMachine::pushState Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreCommandRouter::volumioPushState Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreStateMachine::pushState Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreCommandRouter::volumioPushState Nov 01 18:35:16 volumio-kh volumio[900]: info: ------------------------------ 64ms Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetQueue Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreStateMachine::getQueue Nov 01 18:35:16 volumio-kh volumio[900]: info: CorePlayQueue::getQueue Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreCommandRouter::volumioGetQueue Nov 01 18:35:16 volumio-kh volumio[900]: info: CoreStateMachine::getQueue Nov 01 18:35:16 volumio-kh volumio[900]: info: CorePlayQueue::getQueue Nov 01 18:35:16 volumio-kh volumio[900]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:35:16 volumio-kh volumio[900]: Error: certificate is not yet valid Nov 01 18:35:16 volumio-kh volumio[900]: at TLSSocket.onConnectSecure (_tls_wrap.js:1497:34) Nov 01 18:35:16 volumio-kh volumio[900]: at TLSSocket.emit (events.js:315:20) Nov 01 18:35:16 volumio-kh volumio[900]: at TLSSocket._finishInit (_tls_wrap.js:932:8) Nov 01 18:35:16 volumio-kh volumio[900]: at TLSWrap.ssl.onhandshakedone (_tls_wrap.js:706:12) { Nov 01 18:35:16 volumio-kh volumio[900]: code: 'CERT_NOT_YET_VALID' Nov 01 18:35:16 volumio-kh volumio[900]: } Nov 01 18:35:16 volumio-kh volumio[900]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:35:17 volumio-kh sudo[1172]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2023-11-01 18:34 Nov 01 18:35:17 volumio-kh sudo[1172]: 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="cd8cf34b47ce852e70b71e6f7b6e0265f7fdb695" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="8f88153f9a18f312d56050e6613b45a852ac819a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 27 Sep 2023 11:35:49 AM CEST" VOLUMIO_VERSION="3.546" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6823c0d83061ff736b7e0dd4481bc496"