-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Tue 2023-01-24 15:30:44 UTC. -- Jan 24 15:29:53 volumio671hht kernel: smp: Brought up 1 node, 4 CPUs Jan 24 15:29:53 volumio671hht kernel: SMP: Total of 4 processors activated (432.00 BogoMIPS). Jan 24 15:29:53 volumio671hht kernel: CPU: All CPU(s) started in HYP mode. Jan 24 15:29:53 volumio671hht kernel: CPU: Virtualization extensions available. Jan 24 15:29:53 volumio671hht kernel: devtmpfs: initialized Jan 24 15:29:53 volumio671hht kernel: VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0 Jan 24 15:29:53 volumio671hht kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Jan 24 15:29:53 volumio671hht kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Jan 24 15:29:53 volumio671hht kernel: pinctrl core: initialized pinctrl subsystem Jan 24 15:29:53 volumio671hht kernel: NET: Registered protocol family 16 Jan 24 15:29:53 volumio671hht kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Jan 24 15:29:53 volumio671hht kernel: audit: initializing netlink subsys (disabled) Jan 24 15:29:53 volumio671hht kernel: audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1 Jan 24 15:29:53 volumio671hht kernel: thermal_sys: Registered thermal governor 'step_wise' Jan 24 15:29:53 volumio671hht kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Jan 24 15:29:53 volumio671hht kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Jan 24 15:29:53 volumio671hht kernel: Serial: AMBA PL011 UART driver Jan 24 15:29:53 volumio671hht kernel: bcm2835-mbox fe00b880.mailbox: mailbox enabled Jan 24 15:29:53 volumio671hht kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2022-01-20T13:56:48, variant start Jan 24 15:29:53 volumio671hht kernel: raspberrypi-firmware soc:firmware: Firmware hash is bd88f66f8952d34e4e0613a85c7a6d3da49e13e2 Jan 24 15:29:53 volumio671hht kernel: Kprobes globally optimized Jan 24 15:29:53 volumio671hht kernel: bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 Jan 24 15:29:53 volumio671hht kernel: vgaarb: loaded Jan 24 15:29:53 volumio671hht kernel: SCSI subsystem initialized Jan 24 15:29:53 volumio671hht kernel: usbcore: registered new interface driver usbfs Jan 24 15:29:53 volumio671hht kernel: usbcore: registered new interface driver hub Jan 24 15:29:53 volumio671hht kernel: usbcore: registered new device driver usb Jan 24 15:29:53 volumio671hht kernel: usb_phy_generic phy: supply vcc not found, using dummy regulator Jan 24 15:29:53 volumio671hht kernel: clocksource: Switched to clocksource arch_sys_counter Jan 24 15:29:53 volumio671hht kernel: VFS: Disk quotas dquot_6.6.0 Jan 24 15:29:53 volumio671hht kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Jan 24 15:29:53 volumio671hht kernel: FS-Cache: Loaded Jan 24 15:29:53 volumio671hht kernel: CacheFiles: Loaded Jan 24 15:29:53 volumio671hht kernel: NET: Registered protocol family 2 Jan 24 15:29:53 volumio671hht kernel: IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) Jan 24 15:29:53 volumio671hht kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear) Jan 24 15:29:53 volumio671hht kernel: TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) Jan 24 15:29:53 volumio671hht kernel: TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear) Jan 24 15:29:53 volumio671hht kernel: TCP: Hash tables configured (established 8192 bind 8192) Jan 24 15:29:53 volumio671hht kernel: UDP hash table entries: 512 (order: 2, 16384 bytes, linear) Jan 24 15:29:53 volumio671hht kernel: UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) Jan 24 15:29:53 volumio671hht kernel: NET: Registered protocol family 1 Jan 24 15:29:53 volumio671hht kernel: RPC: Registered named UNIX socket transport module. Jan 24 15:29:53 volumio671hht kernel: RPC: Registered udp transport module. Jan 24 15:29:53 volumio671hht kernel: RPC: Registered tcp transport module. Jan 24 15:29:53 volumio671hht kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Jan 24 15:29:53 volumio671hht kernel: PCI: CLS 0 bytes, default 64 Jan 24 15:29:53 volumio671hht kernel: Trying to unpack rootfs image as initramfs... Jan 24 15:29:53 volumio671hht kernel: Freeing initrd memory: 13036K Jan 24 15:29:53 volumio671hht kernel: Initialise system trusted keyrings Jan 24 15:29:53 volumio671hht kernel: workingset: timestamp_bits=14 max_order=19 bucket_order=5 Jan 24 15:29:53 volumio671hht kernel: zbud: loaded Jan 24 15:29:53 volumio671hht kernel: FS-Cache: Netfs 'nfs' registered for caching Jan 24 15:29:53 volumio671hht kernel: NFS: Registering the id_resolver key type Jan 24 15:29:53 volumio671hht kernel: Key type id_resolver registered Jan 24 15:29:53 volumio671hht kernel: Key type id_legacy registered Jan 24 15:29:53 volumio671hht kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Jan 24 15:29:53 volumio671hht kernel: nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Jan 24 15:29:53 volumio671hht kernel: Key type asymmetric registered Jan 24 15:29:53 volumio671hht kernel: Asymmetric key parser 'x509' registered Jan 24 15:29:53 volumio671hht kernel: bounce: pool size: 64 pages Jan 24 15:29:53 volumio671hht kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249) Jan 24 15:29:53 volumio671hht kernel: io scheduler mq-deadline registered Jan 24 15:29:53 volumio671hht kernel: io scheduler kyber registered Jan 24 15:29:53 volumio671hht kernel: brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: Jan 24 15:29:53 volumio671hht kernel: brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] Jan 24 15:29:53 volumio671hht kernel: brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 Jan 24 15:29:53 volumio671hht kernel: brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x007fffffff -> 0x0400000000 Jan 24 15:29:53 volumio671hht kernel: brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) Jan 24 15:29:53 volumio671hht kernel: brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 Jan 24 15:29:53 volumio671hht kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Jan 24 15:29:53 volumio671hht kernel: pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) Jan 24 15:29:53 volumio671hht kernel: pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 Jan 24 15:29:53 volumio671hht kernel: pci 0000:00:00.0: PME# supported from D0 D3hot Jan 24 15:29:53 volumio671hht kernel: PCI: bus0: Fast back to back transfers disabled Jan 24 15:29:53 volumio671hht kernel: pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 Jan 24 15:29:53 volumio671hht kernel: pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] Jan 24 15:29:53 volumio671hht kernel: pci 0000:01:00.0: PME# supported from D0 D3hot Jan 24 15:29:53 volumio671hht kernel: PCI: bus1: Fast back to back transfers disabled Jan 24 15:29:53 volumio671hht kernel: pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] Jan 24 15:29:53 volumio671hht kernel: pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] Jan 24 15:29:53 volumio671hht kernel: pci 0000:00:00.0: PCI bridge to [bus 01] Jan 24 15:29:53 volumio671hht kernel: pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] Jan 24 15:29:53 volumio671hht kernel: pcieport 0000:00:00.0: enabling device (0140 -> 0142) Jan 24 15:29:53 volumio671hht kernel: pcieport 0000:00:00.0: PME: Signaling with IRQ 62 Jan 24 15:29:53 volumio671hht kernel: bcm2708_fb soc:fb: FB found 1 display(s) Jan 24 15:29:53 volumio671hht kernel: Console: switching to colour frame buffer device 80x30 Jan 24 15:29:53 volumio671hht kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Jan 24 15:29:53 volumio671hht kernel: iproc-rng200 fe104000.rng: hwrng registered Jan 24 15:29:53 volumio671hht kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Jan 24 15:29:53 volumio671hht kernel: gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000 Jan 24 15:29:53 volumio671hht kernel: brd: module loaded Jan 24 15:29:53 volumio671hht kernel: loop: module loaded Jan 24 15:29:53 volumio671hht kernel: Loading iSCSI transport class v2.0-870. Jan 24 15:29:53 volumio671hht kernel: libphy: Fixed MDIO Bus: probed Jan 24 15:29:53 volumio671hht kernel: bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 Jan 24 15:29:53 volumio671hht kernel: libphy: bcmgenet MII bus: probed Jan 24 15:29:53 volumio671hht kernel: unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus Jan 24 15:29:53 volumio671hht kernel: usbcore: registered new interface driver r8152 Jan 24 15:29:53 volumio671hht kernel: usbcore: registered new interface driver lan78xx Jan 24 15:29:53 volumio671hht kernel: usbcore: registered new interface driver smsc95xx Jan 24 15:29:53 volumio671hht kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Jan 24 15:29:53 volumio671hht kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 Jan 24 15:29:53 volumio671hht kernel: xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x00000e0000000890 Jan 24 15:29:53 volumio671hht kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10 Jan 24 15:29:53 volumio671hht kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Jan 24 15:29:53 volumio671hht kernel: usb usb1: Product: xHCI Host Controller Jan 24 15:29:53 volumio671hht kernel: usb usb1: Manufacturer: Linux 5.10.92-v7l+ xhci-hcd Jan 24 15:29:53 volumio671hht kernel: usb usb1: SerialNumber: 0000:01:00.0 Jan 24 15:29:53 volumio671hht kernel: hub 1-0:1.0: USB hub found Jan 24 15:29:53 volumio671hht kernel: hub 1-0:1.0: 1 port detected Jan 24 15:29:53 volumio671hht kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Jan 24 15:29:53 volumio671hht kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Jan 24 15:29:53 volumio671hht kernel: xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Jan 24 15:29:53 volumio671hht kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10 Jan 24 15:29:53 volumio671hht kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Jan 24 15:29:53 volumio671hht kernel: usb usb2: Product: xHCI Host Controller Jan 24 15:29:53 volumio671hht kernel: usb usb2: Manufacturer: Linux 5.10.92-v7l+ xhci-hcd Jan 24 15:29:53 volumio671hht kernel: usb usb2: SerialNumber: 0000:01:00.0 Jan 24 15:29:53 volumio671hht kernel: hub 2-0:1.0: USB hub found Jan 24 15:29:53 volumio671hht kernel: hub 2-0:1.0: 4 ports detected Jan 24 15:29:53 volumio671hht kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Jan 24 15:29:53 volumio671hht kernel: dwc_otg: FIQ enabled Jan 24 15:29:53 volumio671hht kernel: dwc_otg: NAK holdoff enabled Jan 24 15:29:53 volumio671hht kernel: dwc_otg: FIQ split-transaction FSM enabled Jan 24 15:29:53 volumio671hht kernel: Module dwc_common_port init Jan 24 15:29:53 volumio671hht kernel: usbcore: registered new interface driver uas Jan 24 15:29:53 volumio671hht kernel: usbcore: registered new interface driver usb-storage Jan 24 15:29:53 volumio671hht kernel: mousedev: PS/2 mouse device common for all mice Jan 24 15:29:53 volumio671hht kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Jan 24 15:29:53 volumio671hht kernel: sdhci: Secure Digital Host Controller Interface driver Jan 24 15:29:53 volumio671hht kernel: sdhci: Copyright(c) Pierre Ossman Jan 24 15:29:53 volumio671hht kernel: mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe Jan 24 15:29:53 volumio671hht kernel: sdhci-pltfm: SDHCI platform and OF driver helper Jan 24 15:29:53 volumio671hht kernel: ledtrig-cpu: registered to indicate activity on CPUs Jan 24 15:29:53 volumio671hht kernel: hid: raw HID events driver (C) Jiri Kosina Jan 24 15:29:53 volumio671hht kernel: usbcore: registered new interface driver usbhid Jan 24 15:29:53 volumio671hht kernel: usbhid: USB HID core driver Jan 24 15:29:53 volumio671hht kernel: Initializing XFRM netlink socket Jan 24 15:29:53 volumio671hht kernel: NET: Registered protocol family 17 Jan 24 15:29:53 volumio671hht kernel: Key type dns_resolver registered Jan 24 15:29:53 volumio671hht kernel: Registering SWP/SWPB emulation handler Jan 24 15:29:53 volumio671hht kernel: registered taskstats version 1 Jan 24 15:29:53 volumio671hht kernel: Loading compiled-in X.509 certificates Jan 24 15:29:53 volumio671hht kernel: Key type ._fscrypt registered Jan 24 15:29:53 volumio671hht kernel: Key type .fscrypt registered Jan 24 15:29:53 volumio671hht kernel: Key type fscrypt-provisioning registered Jan 24 15:29:53 volumio671hht kernel: uart-pl011 fe201000.serial: there is not valid maps for state default Jan 24 15:29:53 volumio671hht kernel: uart-pl011 fe201000.serial: cts_event_workaround enabled Jan 24 15:29:53 volumio671hht kernel: fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 36, base_baud = 0) is a PL011 rev2 Jan 24 15:29:53 volumio671hht kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Jan 24 15:29:53 volumio671hht kernel: mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 Jan 24 15:29:53 volumio671hht kernel: mmc-bcm2835 fe300000.mmcnr: DMA channel allocated Jan 24 15:29:53 volumio671hht kernel: of_cfs_init Jan 24 15:29:53 volumio671hht kernel: of_cfs_init: OK Jan 24 15:29:53 volumio671hht kernel: mmc1: queuing unknown CIS tuple 0x80 (2 bytes) Jan 24 15:29:53 volumio671hht kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Jan 24 15:29:53 volumio671hht kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Jan 24 15:29:53 volumio671hht kernel: mmc1: queuing unknown CIS tuple 0x80 (7 bytes) Jan 24 15:29:53 volumio671hht kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Jan 24 15:29:53 volumio671hht kernel: mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA Jan 24 15:29:53 volumio671hht kernel: Freeing unused kernel memory: 2048K Jan 24 15:29:53 volumio671hht kernel: Run /init as init process Jan 24 15:29:53 volumio671hht kernel: with arguments: Jan 24 15:29:53 volumio671hht kernel: /init Jan 24 15:29:53 volumio671hht kernel: splash Jan 24 15:29:53 volumio671hht kernel: with environment: Jan 24 15:29:53 volumio671hht kernel: HOME=/ Jan 24 15:29:53 volumio671hht kernel: TERM=linux Jan 24 15:29:53 volumio671hht kernel: imgpart=/dev/mmcblk0p2 Jan 24 15:29:53 volumio671hht kernel: imgfile=/volumio_current.sqsh Jan 24 15:29:53 volumio671hht kernel: bootdelay=5 Jan 24 15:29:53 volumio671hht kernel: mmc1: new high speed SDIO card at address 0001 Jan 24 15:29:53 volumio671hht kernel: mmc0: new ultra high speed DDR50 SDHC card at address aaaa Jan 24 15:29:53 volumio671hht kernel: mmcblk0: mmc0:aaaa SC32G 29.7 GiB Jan 24 15:29:53 volumio671hht kernel: mmcblk0: p1 p2 p3 Jan 24 15:29:53 volumio671hht kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd Jan 24 15:29:53 volumio671hht initramfs: Booting Volumio for BCM2711 Jan 24 15:29:53 volumio671hht initramfs: This script mounts rootfs RO with an overlay RW layer. Jan 24 15:29:53 volumio671hht kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Jan 24 15:29:53 volumio671hht initramfs: IMGPART=/dev/mmcblk0p2 Jan 24 15:29:53 volumio671hht initramfs: IMGFILE=/volumio_current.sqsh Jan 24 15:29:53 volumio671hht initramfs: Boot delay (except first time) will be 5 seconds Jan 24 15:29:53 volumio671hht initramfs: /dev/mmcblk0p2: Jan 24 15:29:53 volumio671hht kernel: usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 Jan 24 15:29:53 volumio671hht kernel: usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Jan 24 15:29:53 volumio671hht kernel: usb 1-1: Product: USB2.0 Hub Jan 24 15:29:53 volumio671hht kernel: hub 1-1:1.0: USB hub found Jan 24 15:29:53 volumio671hht kernel: hub 1-1:1.0: 4 ports detected Jan 24 15:29:53 volumio671hht kernel: EXT4-fs (mmcblk0p2): recovery complete Jan 24 15:29:53 volumio671hht kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) Jan 24 15:29:53 volumio671hht initramfs: Doing a 5 second delay here to give kernel load a headstart Jan 24 15:29:53 volumio671hht kernel: usb 1-1.2: new high-speed USB device number 3 using xhci_hcd Jan 24 15:29:53 volumio671hht kernel: usb 1-1.2: New USB device found, idVendor=154e, idProduct=1008, bcdDevice= 0.03 Jan 24 15:29:53 volumio671hht kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=3, SerialNumber=0 Jan 24 15:29:53 volumio671hht kernel: usb 1-1.2: Product: DA-310USB Jan 24 15:29:53 volumio671hht kernel: usb 1-1.2: Manufacturer: D&M Holdings Inc. Jan 24 15:29:53 volumio671hht initramfs: Checking for USB updates Jan 24 15:29:53 volumio671hht initramfs: No USB device detected (when incorrect, try adding 'bootdelay=5' to your boot cmdline) Jan 24 15:29:53 volumio671hht kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Jan 24 15:29:53 volumio671hht kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Jan 24 15:29:53 volumio671hht kernel: EXT4-fs (mmcblk0p3): recovery complete Jan 24 15:29:53 volumio671hht kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null) Jan 24 15:29:53 volumio671hht initramfs: With Option: Jan 24 15:29:53 volumio671hht initramfs: VOLUMIO_VERSION="3.251" Jan 24 15:29:53 volumio671hht initramfs: Finish initramfs, continue booting Volumio Jan 24 15:29:53 volumio671hht systemd[1]: System time before build time, advancing clock. Jan 24 15:29:53 volumio671hht kernel: NET: Registered protocol family 10 Jan 24 15:29:53 volumio671hht kernel: Segment Routing with IPv6 Jan 24 15:29:53 volumio671hht 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) Jan 24 15:29:53 volumio671hht systemd[1]: Detected architecture arm. Jan 24 15:29:53 volumio671hht systemd[1]: Set hostname to . Jan 24 15:29:53 volumio671hht 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. Jan 24 15:29:53 volumio671hht kernel: random: systemd: uninitialized urandom read (16 bytes read) Jan 24 15:29:53 volumio671hht kernel: random: systemd: uninitialized urandom read (16 bytes read) Jan 24 15:29:53 volumio671hht kernel: random: systemd: uninitialized urandom read (16 bytes read) Jan 24 15:29:53 volumio671hht systemd[1]: Listening on udev Control Socket. Jan 24 15:29:53 volumio671hht systemd[1]: Started Forward Password Requests to Wall Directory Watch. Jan 24 15:29:53 volumio671hht systemd[1]: Listening on udev Kernel Socket. Jan 24 15:29:53 volumio671hht systemd[1]: Listening on Journal Socket. Jan 24 15:29:53 volumio671hht systemd[1]: Listening on fsck to fsckd communication Socket. Jan 24 15:29:53 volumio671hht systemd[1]: Mounting RPC Pipe File System... Jan 24 15:29:53 volumio671hht kernel: i2c /dev entries driver Jan 24 15:29:53 volumio671hht systemd-journald[205]: Journal started Jan 24 15:29:53 volumio671hht systemd-journald[205]: Runtime journal (/run/log/journal/785f013f15a7766cb54a2cb06217cae8) is 7.5M, max 30.0M, 22.5M free. Jan 24 15:29:53 volumio671hht systemd-modules-load[206]: Inserted module 'i2c_dev' Jan 24 15:29:53 volumio671hht fake-hwclock[196]: Tue Jan 24 15:29:53 UTC 2023 Jan 24 15:29:53 volumio671hht systemd[1]: Started Create System Users. Jan 24 15:29:53 volumio671hht systemd[1]: Starting Create Static Device Nodes in /dev... Jan 24 15:29:53 volumio671hht systemd[1]: Started Create Static Device Nodes in /dev. Jan 24 15:29:53 volumio671hht systemd[1]: Reached target Local File Systems (Pre). Jan 24 15:29:53 volumio671hht systemd[1]: Mounting /var/spool/cups... Jan 24 15:29:53 volumio671hht systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Jan 24 15:29:53 volumio671hht systemd[1]: Mounting /tmp... Jan 24 15:29:53 volumio671hht systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Jan 24 15:29:53 volumio671hht systemd[1]: Mounting /var/log... Jan 24 15:29:53 volumio671hht systemd[1]: Starting udev Kernel Device Manager... Jan 24 15:29:53 volumio671hht systemd[1]: Mounted /var/spool/cups. Jan 24 15:29:53 volumio671hht systemd[1]: Mounted /tmp. Jan 24 15:29:53 volumio671hht systemd[1]: Mounting /var/spool/cups/tmp... Jan 24 15:29:53 volumio671hht systemd[1]: Mounted /var/log. Jan 24 15:29:53 volumio671hht systemd[1]: Starting Flush Journal to Persistent Storage... Jan 24 15:29:53 volumio671hht systemd[1]: Mounted /var/spool/cups/tmp. Jan 24 15:29:53 volumio671hht systemd[1]: Started udev Coldplug all Devices. Jan 24 15:29:53 volumio671hht systemd-udevd[225]: Network interface NamePolicy= disabled on kernel command line, ignoring. Jan 24 15:29:53 volumio671hht systemd[1]: Starting Helper to synchronize boot up for ifupdown... Jan 24 15:29:53 volumio671hht systemd-journald[205]: Runtime journal (/run/log/journal/785f013f15a7766cb54a2cb06217cae8) is 7.5M, max 30.0M, 22.5M free. Jan 24 15:29:53 volumio671hht systemd[1]: Started Flush Journal to Persistent Storage. Jan 24 15:29:53 volumio671hht systemd[1]: Started udev Kernel Device Manager. Jan 24 15:29:53 volumio671hht systemd[1]: Starting Show Plymouth Boot Screen... Jan 24 15:29:53 volumio671hht systemd[1]: Received SIGRTMIN+20 from PID 245 (plymouthd). Jan 24 15:29:53 volumio671hht systemd[1]: Started Show Plymouth Boot Screen. Jan 24 15:29:53 volumio671hht systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Jan 24 15:29:53 volumio671hht systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jan 24 15:29:53 volumio671hht systemd[1]: Reached target Local Encrypted Volumes. Jan 24 15:29:53 volumio671hht systemd[1]: Reached target Paths. Jan 24 15:29:53 volumio671hht systemd-udevd[242]: Using default interface naming scheme 'v240'. Jan 24 15:29:53 volumio671hht kernel: rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000 Jan 24 15:29:53 volumio671hht kernel: rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000 Jan 24 15:29:53 volumio671hht kernel: rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000 Jan 24 15:29:53 volumio671hht kernel: rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000 Jan 24 15:29:54 volumio671hht kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Jan 24 15:29:54 volumio671hht kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Jan 24 15:29:54 volumio671hht kernel: [vc_sm_connected_init]: start Jan 24 15:29:54 volumio671hht kernel: [vc_sm_connected_init]: installed successfully Jan 24 15:29:54 volumio671hht kernel: mc: Linux media interface: v0.10 Jan 24 15:29:54 volumio671hht kernel: videodev: Linux video capture interface: v2.00 Jan 24 15:29:54 volumio671hht kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Jan 24 15:29:54 volumio671hht kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Jan 24 15:29:54 volumio671hht kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jan 24 15:29:54 volumio671hht kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jan 24 15:29:54 volumio671hht kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Jan 24 15:29:54 volumio671hht kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Jan 24 15:29:54 volumio671hht kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Jan 24 15:29:54 volumio671hht kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Jan 24 15:29:54 volumio671hht kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Jan 24 15:29:54 volumio671hht kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Jan 24 15:29:54 volumio671hht kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Jan 24 15:29:54 volumio671hht kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Jan 24 15:29:54 volumio671hht kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Jan 24 15:29:54 volumio671hht kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Jan 24 15:29:54 volumio671hht systemd-udevd[242]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jan 24 15:29:54 volumio671hht kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Jan 24 15:29:54 volumio671hht kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Jan 24 15:29:54 volumio671hht kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Jan 24 15:29:54 volumio671hht systemd[1]: Found device /dev/mmcblk0p1. Jan 24 15:29:54 volumio671hht kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Jan 24 15:29:54 volumio671hht systemd-udevd[232]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jan 24 15:29:54 volumio671hht kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Jan 24 15:29:55 volumio671hht kernel: snd_usb_audio: unknown parameter 'nrpacks' ignored Jan 24 15:29:55 volumio671hht kernel: usb 1-1.2: 1:3 : unsupported format bits 0x100000000 Jan 24 15:29:55 volumio671hht kernel: usbcore: registered new interface driver snd-usb-audio Jan 24 15:29:55 volumio671hht kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Jan 24 15:29:55 volumio671hht kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Jan 24 15:29:55 volumio671hht kernel: usbcore: registered new interface driver brcmfmac Jan 24 15:29:56 volumio671hht kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Jan 24 15:29:56 volumio671hht kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Jan 24 15:29:56 volumio671hht kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Jan 4 2021 19:56:29 version 7.45.229 (617f1f5 CY) FWID 01-2dbd9d2e Jan 24 15:29:56 volumio671hht systemd-udevd[233]: Using default interface naming scheme 'v240'. Jan 24 15:29:56 volumio671hht systemd-udevd[233]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jan 24 15:29:56 volumio671hht systemd-udevd[241]: Process '/lib/crda/setregdomain' failed with exit code 1. Jan 24 15:29:57 volumio671hht systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Jan 24 15:29:57 volumio671hht systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jan 24 15:29:57 volumio671hht systemd[1]: Condition check resulted in Huge Pages File System being skipped. Jan 24 15:29:57 volumio671hht systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Jan 24 15:29:57 volumio671hht systemd[1]: Condition check resulted in FUSE Control File System being skipped. Jan 24 15:29:57 volumio671hht systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Jan 24 15:29:57 volumio671hht systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Jan 24 15:29:57 volumio671hht systemd[1]: Starting File System Check on /dev/mmcblk0p1... Jan 24 15:29:57 volumio671hht systemd[1]: Starting Load/Save RF Kill Switch Status... Jan 24 15:29:57 volumio671hht systemd-udevd[246]: Process '/bin/bash -c '/usr/local/bin/volumio usbattach'' failed with exit code 7. Jan 24 15:29:57 volumio671hht systemd[1]: Started File System Check Daemon to report status. Jan 24 15:29:57 volumio671hht systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Jan 24 15:29:57 volumio671hht systemd[1]: Started Load/Save RF Kill Switch Status. Jan 24 15:29:57 volumio671hht systemd-fsck[363]: fsck.fat 4.1 (2017-01-24) Jan 24 15:29:57 volumio671hht systemd-fsck[363]: 0x25: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Jan 24 15:29:57 volumio671hht systemd-fsck[363]: Automatically removing dirty bit. Jan 24 15:29:57 volumio671hht systemd-fsck[363]: Performing changes. Jan 24 15:29:57 volumio671hht systemd-fsck[363]: /dev/mmcblk0p1: 297 files, 27490/46774 clusters Jan 24 15:29:57 volumio671hht systemd[1]: Started Helper to synchronize boot up for ifupdown. Jan 24 15:29:57 volumio671hht systemd[1]: Started File System Check on /dev/mmcblk0p1. Jan 24 15:29:57 volumio671hht systemd[1]: Mounting /boot... Jan 24 15:29:57 volumio671hht systemd[1]: Mounted /boot. Jan 24 15:29:57 volumio671hht systemd[1]: Reached target Local File Systems. Jan 24 15:29:57 volumio671hht systemd[1]: Starting Preprocess NFS configuration... Jan 24 15:29:57 volumio671hht systemd[1]: Started ifup for wlan0. Jan 24 15:29:57 volumio671hht systemd[1]: Starting Create Volatile Files and Directories... Jan 24 15:29:57 volumio671hht systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Jan 24 15:29:57 volumio671hht systemd[1]: Started ifup for eth0. Jan 24 15:29:57 volumio671hht systemd[1]: Starting Raise network interfaces... Jan 24 15:29:57 volumio671hht systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Jan 24 15:29:57 volumio671hht systemd[1]: nfs-config.service: Succeeded. Jan 24 15:29:57 volumio671hht systemd[1]: Started Preprocess NFS configuration. Jan 24 15:29:57 volumio671hht systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Jan 24 15:29:57 volumio671hht systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Jan 24 15:29:57 volumio671hht systemd[1]: Reached target NFS client services. Jan 24 15:29:58 volumio671hht systemd[1]: Received SIGRTMIN+20 from PID 245 (plymouthd). Jan 24 15:29:58 volumio671hht systemd[1]: plymouth-read-write.service: Succeeded. Jan 24 15:29:58 volumio671hht systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Jan 24 15:29:58 volumio671hht systemd[1]: Started Create Volatile Files and Directories. Jan 24 15:29:58 volumio671hht systemd[1]: Starting RPC bind portmap service... Jan 24 15:29:58 volumio671hht systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Jan 24 15:29:58 volumio671hht systemd[1]: Starting Update UTMP about System Boot/Shutdown... Jan 24 15:29:58 volumio671hht systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Jan 24 15:29:58 volumio671hht systemd[1]: Started Update UTMP about System Boot/Shutdown. Jan 24 15:29:58 volumio671hht systemd[1]: Reached target System Initialization. Jan 24 15:29:58 volumio671hht systemd[1]: Listening on mpd.socket. Jan 24 15:29:58 volumio671hht systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Jan 24 15:29:58 volumio671hht systemd[1]: Started Daily Cleanup of Temporary Directories. Jan 24 15:29:58 volumio671hht systemd[1]: Listening on triggerhappy.socket. Jan 24 15:29:58 volumio671hht systemd[1]: apt-daily.timer: Not using persistent file timestamp Wed 2023-01-25 16:52:02 UTC as it is in the future. Jan 24 15:29:58 volumio671hht systemd[1]: Started Daily apt download activities. Jan 24 15:29:58 volumio671hht systemd[1]: apt-daily-upgrade.timer: Not using persistent file timestamp Wed 2023-01-25 06:14:20 UTC as it is in the future. Jan 24 15:29:58 volumio671hht systemd[1]: Started Daily apt upgrade and clean activities. Jan 24 15:29:58 volumio671hht systemd[1]: Reached target Timers. Jan 24 15:29:58 volumio671hht systemd[1]: Listening on D-Bus System Message Bus Socket. Jan 24 15:29:58 volumio671hht systemd[1]: Reached target Sockets. Jan 24 15:29:58 volumio671hht systemd[1]: Reached target Basic System. Jan 24 15:29:58 volumio671hht systemd[1]: Starting triggerhappy global hotkey daemon... Jan 24 15:29:58 volumio671hht systemd[1]: Starting Wireless Services... Jan 24 15:29:58 volumio671hht systemd[1]: Started UPnP Renderer front-end to MPD. Jan 24 15:29:58 volumio671hht systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Jan 24 15:29:58 volumio671hht systemd[1]: Starting dhcpcd on all interfaces... Jan 24 15:29:58 volumio671hht systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Jan 24 15:29:58 volumio671hht systemd[1]: Started volumio-remote-updater.service. Jan 24 15:29:58 volumio671hht systemd[1]: Started Manage Sound Card State (restore and store). Jan 24 15:29:58 volumio671hht alsactl[451]: alsactl 1.1.8 daemon started Jan 24 15:29:58 volumio671hht systemd[1]: Started Volumio Iptables Module. Jan 24 15:29:58 volumio671hht kernel: 8021q: 802.1Q VLAN Support v1.8 Jan 24 15:29:58 volumio671hht thd[444]: Unable to parse trigger line: Jan 24 15:29:58 volumio671hht thd[444]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Jan 24 15:29:58 volumio671hht thd[444]: Unable to parse trigger line: Jan 24 15:29:58 volumio671hht thd[444]: Found socket passed from systemd Jan 24 15:29:58 volumio671hht dhcpcd[449]: Not running dhcpcd because /etc/network/interfaces Jan 24 15:29:58 volumio671hht dhcpcd[449]: defines some interfaces that will use a Jan 24 15:29:58 volumio671hht dhcpcd[449]: DHCP client or static address Jan 24 15:29:58 volumio671hht systemd[1]: Starting Save/Restore Sound Card State... Jan 24 15:29:58 volumio671hht systemd[1]: Started D-Bus System Message Bus. Jan 24 15:29:58 volumio671hht systemd[1]: Starting WPA supplicant... Jan 24 15:29:58 volumio671hht systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Jan 24 15:29:58 volumio671hht systemd[1]: Starting Login Service... Jan 24 15:29:58 volumio671hht systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Jan 24 15:29:58 volumio671hht systemd[1]: Starting Configure Bluetooth Modems connected by UART... Jan 24 15:29:58 volumio671hht systemd[1]: Started RPC bind portmap service. Jan 24 15:29:58 volumio671hht systemd[1]: Started triggerhappy global hotkey daemon. Jan 24 15:29:58 volumio671hht systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Jan 24 15:29:58 volumio671hht systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Jan 24 15:29:58 volumio671hht systemd[1]: Failed to start dhcpcd on all interfaces. Jan 24 15:29:58 volumio671hht systemd[1]: Started Save/Restore Sound Card State. Jan 24 15:29:58 volumio671hht systemd[1]: Reached target Sound Card. Jan 24 15:29:58 volumio671hht systemd[1]: Reached target RPC Port Mapper. Jan 24 15:29:58 volumio671hht systemd[1]: Reached target Remote File Systems (Pre). Jan 24 15:29:58 volumio671hht systemd[1]: Reached target Remote File Systems. Jan 24 15:29:58 volumio671hht systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Jan 24 15:29:58 volumio671hht ifup[374]: ifup: waiting for lock on /run/network/ifstate.wlan0 Jan 24 15:29:59 volumio671hht avahi-daemon[468]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Jan 24 15:29:59 volumio671hht avahi-daemon[468]: Successfully dropped root privileges. Jan 24 15:29:59 volumio671hht avahi-daemon[468]: avahi-daemon 0.7 starting up. Jan 24 15:29:59 volumio671hht sh[373]: eth0: waiting for carrier Jan 24 15:29:59 volumio671hht dhcpcd[417]: eth0: waiting for carrier Jan 24 15:29:59 volumio671hht kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Jan 24 15:29:59 volumio671hht kernel: bcmgenet fd580000.ethernet eth0: Link is Down Jan 24 15:29:59 volumio671hht systemd-logind[469]: New seat seat0. Jan 24 15:29:59 volumio671hht systemd[1]: Started Login Service. Jan 24 15:29:59 volumio671hht avahi-daemon[468]: Successfully called chroot(). Jan 24 15:29:59 volumio671hht avahi-daemon[468]: Successfully dropped remaining capabilities. Jan 24 15:29:59 volumio671hht kernel: uart-pl011 fe201000.serial: no DMA platform data Jan 24 15:29:59 volumio671hht avahi-daemon[468]: Loading service file /services/volumio.service. Jan 24 15:29:59 volumio671hht avahi-daemon[468]: Network interface enumeration completed. Jan 24 15:29:59 volumio671hht avahi-daemon[468]: Server startup complete. Host name is volumio671hht.local. Local service cookie is 319113371. Jan 24 15:29:59 volumio671hht avahi-daemon[468]: Service "Volumio671hht" (/services/volumio.service) successfully established. Jan 24 15:29:59 volumio671hht sh[370]: wlan0=wlan0 Jan 24 15:29:59 volumio671hht systemd[1]: Started Avahi mDNS/DNS-SD Stack. Jan 24 15:29:59 volumio671hht systemd[1]: Started Raise network interfaces. Jan 24 15:29:59 volumio671hht loadcpufreq[484]: Loading cpufreq kernel modules...done (none). Jan 24 15:29:59 volumio671hht systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Jan 24 15:29:59 volumio671hht systemd[1]: Starting LSB: set CPUFreq kernel parameters... Jan 24 15:30:00 volumio671hht cpufrequtils[563]: CPUFreq Utilities: Setting performance CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Jan 24 15:30:00 volumio671hht systemd[1]: Started LSB: set CPUFreq kernel parameters. Jan 24 15:30:00 volumio671hht volumio-remote-updater[450]: Error: No active session Jan 24 15:30:00 volumio671hht volumio-remote-updater[450]: [2023-01-24 15:30:00] [info] asio async_connect error: system:111 (Connection refused) Jan 24 15:30:00 volumio671hht volumio-remote-updater[450]: [2023-01-24 15:30:00] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 24 15:30:00 volumio671hht volumio-remote-updater[450]: [2023-01-24 15:30:00] [error] handle_connect error: Underlying Transport Error Jan 24 15:30:00 volumio671hht systemd[1]: Started WPA supplicant. Jan 24 15:30:00 volumio671hht systemd[1]: Reached target Network. Jan 24 15:30:00 volumio671hht wpa_supplicant[467]: Successfully initialized wpa_supplicant Jan 24 15:30:00 volumio671hht systemd[1]: Starting OpenBSD Secure Shell server... Jan 24 15:30:00 volumio671hht systemd[1]: Starting Network Time Service... Jan 24 15:30:00 volumio671hht systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Jan 24 15:30:00 volumio671hht systemd[1]: Starting Music Player Daemon... Jan 24 15:30:00 volumio671hht systemd[1]: Reached target Network is Online. Jan 24 15:30:00 volumio671hht systemd[1]: Starting Samba NMB Daemon... Jan 24 15:30:00 volumio671hht systemd[1]: Starting LSB: Brings up/down network automatically... Jan 24 15:30:00 volumio671hht systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 24 15:30:00 volumio671hht systemd[1]: Starting Permit User Sessions... Jan 24 15:30:00 volumio671hht systemd[1]: Starting /etc/rc.local Compatibility... Jan 24 15:30:00 volumio671hht systemd[1]: Started Permit User Sessions. Jan 24 15:30:00 volumio671hht ntpd[583]: ntpd 4.2.8p12@1.3728-o (1): Starting Jan 24 15:30:00 volumio671hht ntpd[583]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Jan 24 15:30:00 volumio671hht systemd[1]: Started Network Time Service. Jan 24 15:30:00 volumio671hht systemd[1]: iptables.service: Succeeded. Jan 24 15:30:00 volumio671hht ntpd[610]: proto: precision = 0.815 usec (-20) Jan 24 15:30:00 volumio671hht rc.local[594]: Powering off HDMI Jan 24 15:30:00 volumio671hht ifplugd(eth0)[617]: ifplugd 0.28 initializing. Jan 24 15:30:00 volumio671hht systemd[1]: Started /etc/rc.local Compatibility. Jan 24 15:30:00 volumio671hht ifplugd(eth0)[617]: Using interface eth0/E4:5F:01:7A:E4:43 with driver (version: 5.10.92-v7l+) Jan 24 15:30:00 volumio671hht systemd[1]: Starting Terminate Plymouth Boot Screen... Jan 24 15:30:00 volumio671hht ifplugd(eth0)[617]: Using detection mode: SIOCETHTOOL Jan 24 15:30:00 volumio671hht ifplugd(eth0)[617]: Initialization complete, link beat not detected. Jan 24 15:30:00 volumio671hht ntpd[610]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jan 24 15:30:00 volumio671hht ntpd[610]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-06-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jan 24 15:30:00 volumio671hht ntpd[610]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 211 days ago Jan 24 15:30:00 volumio671hht ntpd[610]: Listen and drop on 0 v6wildcard [::]:123 Jan 24 15:30:00 volumio671hht ntpd[610]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jan 24 15:30:00 volumio671hht ntpd[610]: Listen normally on 2 lo 127.0.0.1:123 Jan 24 15:30:00 volumio671hht ntpd[610]: Listening on routing socket on fd #19 for interface updates Jan 24 15:30:00 volumio671hht ntpd[610]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 24 15:30:00 volumio671hht ntpd[610]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 24 15:30:00 volumio671hht systemd[1]: Starting Hold until boot process finishes up... Jan 24 15:30:00 volumio671hht systemd[1]: Received SIGRTMIN+21 from PID 245 (plymouthd). Jan 24 15:30:00 volumio671hht kernel: raspberrypi-firmware soc:firmware: Request 0x00048003 returned status 0x80000001 Jan 24 15:30:00 volumio671hht kernel: bcm2708_fb soc:fb: Failed to allocate GPU framebuffer (-22) Jan 24 15:30:00 volumio671hht kernel: detected fb_set_par error, error code: -22 Jan 24 15:30:00 volumio671hht kernel: raspberrypi-firmware soc:firmware: Request 0x00048003 returned status 0x80000001 Jan 24 15:30:00 volumio671hht kernel: bcm2708_fb soc:fb: Failed to allocate GPU framebuffer (-22) Jan 24 15:30:00 volumio671hht kernel: bcm2708_fb_pan_display(0,0) returns=-22 Jan 24 15:30:00 volumio671hht systemd[1]: plymouth-start.service: Succeeded. Jan 24 15:30:00 volumio671hht systemd[1]: plymouth-quit.service: Succeeded. Jan 24 15:30:00 volumio671hht systemd[1]: Started Terminate Plymouth Boot Screen. Jan 24 15:30:00 volumio671hht systemd[1]: plymouth-quit-wait.service: Succeeded. Jan 24 15:30:00 volumio671hht systemd[1]: Started Hold until boot process finishes up. Jan 24 15:30:00 volumio671hht systemd[1]: Received SIGRTMIN+21 from PID 245 (n/a). Jan 24 15:30:00 volumio671hht systemd[1]: Started Getty on tty1. Jan 24 15:30:00 volumio671hht systemd[1]: Reached target Login Prompts. Jan 24 15:30:00 volumio671hht volumio[448]: Could not open config: /tmp/upmpdcli.conf Jan 24 15:30:00 volumio671hht systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 24 15:30:00 volumio671hht systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 24 15:30:00 volumio671hht ifplugd[589]: Network Interface Plugging Daemon...start eth0...done. Jan 24 15:30:00 volumio671hht systemd[1]: Started LSB: Brings up/down network automatically. Jan 24 15:30:00 volumio671hht haveged[418]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Jan 24 15:30:00 volumio671hht haveged[418]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Jan 24 15:30:00 volumio671hht haveged[418]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99677 Jan 24 15:30:00 volumio671hht haveged[418]: haveged: fills: 0, generated: 0 Jan 24 15:30:01 volumio671hht kernel: random: crng init done Jan 24 15:30:01 volumio671hht kernel: random: 7 urandom warning(s) missed due to ratelimiting Jan 24 15:30:01 volumio671hht sshd[625]: Server listening on 0.0.0.0 port 22. Jan 24 15:30:01 volumio671hht sshd[625]: Server listening on :: port 22. Jan 24 15:30:01 volumio671hht systemd[1]: Started OpenBSD Secure Shell server. Jan 24 15:30:01 volumio671hht ntpd[610]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jan 24 15:30:02 volumio671hht nmbd[596]: [2023/01/24 15:30:02.101960, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Jan 24 15:30:02 volumio671hht nmbd[596]: started asyncdns process 632 Jan 24 15:30:02 volumio671hht nmbd[596]: [2023/01/24 15:30:02.109197, 0] ../lib/util/become_daemon.c:149(daemon_status) Jan 24 15:30:02 volumio671hht nmbd[596]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Jan 24 15:30:02 volumio671hht nmbd[596]: [2023/01/24 15:30:02.110672, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Jan 24 15:30:02 volumio671hht nmbd[596]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jan 24 15:30:02 volumio671hht wireless.js[446]: WIRELESS DAEMON: start Jan 24 15:30:02 volumio671hht wireless.js[446]: WIRELESS: Loaded configuration Jan 24 15:30:02 volumio671hht wireless.js[446]: Cleaning previous... Jan 24 15:30:02 volumio671hht ntpd[610]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jan 24 15:30:02 volumio671hht systemd[1]: systemd-rfkill.service: Succeeded. Jan 24 15:30:02 volumio671hht sudo[636]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 24 15:30:02 volumio671hht sudo[636]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:02 volumio671hht sudo[636]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:02 volumio671hht sudo[638]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 24 15:30:02 volumio671hht sudo[638]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:02 volumio671hht sudo[638]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:02 volumio671hht wireless.js[446]: Stopped aP Jan 24 15:30:02 volumio671hht wireless.js[446]: Wireless Networking DISABLED, not starting wireless flow Jan 24 15:30:02 volumio671hht systemd[1]: wireless.service: Succeeded. Jan 24 15:30:02 volumio671hht systemd[1]: Started Wireless Services. Jan 24 15:30:02 volumio671hht systemd[1]: Started Volumio Backend Module. Jan 24 15:30:02 volumio671hht systemd[1]: Started Volumio Streaming Daemon. Jan 24 15:30:03 volumio671hht volumio-streaming-daemon[646]: ############################ Jan 24 15:30:03 volumio671hht volumio-streaming-daemon[646]: # Volumio Streaming Daemon # Jan 24 15:30:03 volumio671hht volumio-streaming-daemon[646]: # Running on port 7777 # Jan 24 15:30:03 volumio671hht volumio-streaming-daemon[646]: ############################ Jan 24 15:30:03 volumio671hht volumio-streaming-daemon[646]: Environment: production Jan 24 15:30:03 volumio671hht sh[373]: eth0: carrier acquired Jan 24 15:30:03 volumio671hht dhcpcd[417]: eth0: carrier acquired Jan 24 15:30:03 volumio671hht mpd[621]: Jan 24 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 24 15:30:03 volumio671hht kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Jan 24 15:30:03 volumio671hht sh[373]: DUID 00:01:00:01:29:aa:89:1b:e4:5f:01:7a:e4:43 Jan 24 15:30:03 volumio671hht sh[373]: eth0: IAID 01:7a:e4:43 Jan 24 15:30:03 volumio671hht sh[373]: eth0: adding address fe80::e65f:1ff:fe7a:e443 Jan 24 15:30:03 volumio671hht dhcpcd[417]: DUID 00:01:00:01:29:aa:89:1b:e4:5f:01:7a:e4:43 Jan 24 15:30:03 volumio671hht sh[373]: ipv6_addaddr1: Permission denied Jan 24 15:30:03 volumio671hht dhcpcd[417]: eth0: IAID 01:7a:e4:43 Jan 24 15:30:03 volumio671hht dhcpcd[417]: eth0: adding address fe80::e65f:1ff:fe7a:e443 Jan 24 15:30:03 volumio671hht dhcpcd[417]: ipv6_addaddr1: Permission denied Jan 24 15:30:03 volumio671hht mpd[621]: Jan 24 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jan 24 15:30:03 volumio671hht mpd[621]: Jan 24 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jan 24 15:30:03 volumio671hht systemd[1]: Started Music Player Daemon. Jan 24 15:30:03 volumio671hht ntpd[610]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jan 24 15:30:03 volumio671hht ifplugd(eth0)[617]: Link beat detected. Jan 24 15:30:03 volumio671hht ifplugd(eth0)[617]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Jan 24 15:30:03 volumio671hht ifplugd(eth0)[617]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Jan 24 15:30:04 volumio671hht sh[373]: eth0: soliciting an IPv6 router Jan 24 15:30:04 volumio671hht dhcpcd[417]: eth0: soliciting an IPv6 router Jan 24 15:30:04 volumio671hht sh[373]: eth0: rebinding lease of 192.168.1.199 Jan 24 15:30:04 volumio671hht dhcpcd[417]: eth0: rebinding lease of 192.168.1.199 Jan 24 15:30:04 volumio671hht sh[373]: eth0: probing address 192.168.1.199/24 Jan 24 15:30:04 volumio671hht dhcpcd[417]: eth0: probing address 192.168.1.199/24 Jan 24 15:30:04 volumio671hht ntpd[610]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jan 24 15:30:04 volumio671hht volumio[645]: info: ------------------------------------------- Jan 24 15:30:04 volumio671hht volumio[645]: info: ----- Volumio3 ---- Jan 24 15:30:04 volumio671hht volumio[645]: info: ------------------------------------------- Jan 24 15:30:04 volumio671hht volumio[645]: info: ----- System startup ---- Jan 24 15:30:04 volumio671hht volumio[645]: info: ------------------------------------------- Jan 24 15:30:05 volumio671hht volumio-remote-updater[450]: [2023-01-24 15:30:05] [connect] Successful connection Jan 24 15:30:05 volumio671hht volumio[645]: info: MYVOLUMIO Environment detected Jan 24 15:30:05 volumio671hht volumio[645]: info: Plugin folders cleanup Jan 24 15:30:05 volumio671hht volumio[645]: info: Scanning into folder /volumio/app/plugins/ Jan 24 15:30:05 volumio671hht volumio[645]: info: Scanning category audio_interface Jan 24 15:30:05 volumio671hht volumio[645]: info: Scanning category miscellanea Jan 24 15:30:05 volumio671hht volumio[645]: info: Scanning category music_service Jan 24 15:30:05 volumio671hht volumio[645]: info: Scanning category plugins.json Jan 24 15:30:05 volumio671hht volumio[645]: info: Scanning category system_controller Jan 24 15:30:05 volumio671hht volumio[645]: info: Scanning category user_interface Jan 24 15:30:05 volumio671hht volumio[645]: info: Scanning into folder /data/plugins/ Jan 24 15:30:05 volumio671hht volumio[645]: info: Plugin folders cleanup completed Jan 24 15:30:05 volumio671hht volumio[645]: info: ------------------------------------------- Jan 24 15:30:05 volumio671hht volumio[645]: info: ----- Core plugins startup ---- Jan 24 15:30:05 volumio671hht volumio[645]: info: ------------------------------------------- Jan 24 15:30:05 volumio671hht volumio[645]: info: Loading plugins from folder /volumio/app/plugins/ Jan 24 15:30:05 volumio671hht volumio[645]: info: Adding plugin upnp to MyMusic Plugins Jan 24 15:30:05 volumio671hht volumio[645]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 24 15:30:05 volumio671hht volumio[645]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 24 15:30:05 volumio671hht volumio[645]: info: Loading plugins from folder /data/plugins/ Jan 24 15:30:05 volumio671hht volumio[645]: info: Loading plugin "system"... Jan 24 15:30:05 volumio671hht kernel: raspberrypi-firmware soc:firmware: Request 0x00048003 returned status 0x80000001 Jan 24 15:30:05 volumio671hht kernel: bcm2708_fb soc:fb: Failed to allocate GPU framebuffer (-22) Jan 24 15:30:05 volumio671hht kernel: bcm2708_fb_pan_display(0,0) returns=-22 Jan 24 15:30:05 volumio671hht volumio[645]: info: Loading plugin "appearance"... Jan 24 15:30:06 volumio671hht kernel: Bluetooth: Core ver 2.22 Jan 24 15:30:06 volumio671hht kernel: NET: Registered protocol family 31 Jan 24 15:30:06 volumio671hht kernel: Bluetooth: HCI device and connection manager initialized Jan 24 15:30:06 volumio671hht kernel: Bluetooth: HCI socket layer initialized Jan 24 15:30:06 volumio671hht kernel: Bluetooth: L2CAP socket layer initialized Jan 24 15:30:06 volumio671hht kernel: Bluetooth: SCO socket layer initialized Jan 24 15:30:06 volumio671hht btuart[471]: bcm43xx_init Jan 24 15:30:06 volumio671hht btuart[471]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd Jan 24 15:30:06 volumio671hht btuart[471]: Set Controller UART speed to 3000000 bit/s Jan 24 15:30:06 volumio671hht btuart[471]: Device setup complete Jan 24 15:30:06 volumio671hht kernel: Bluetooth: HCI UART driver ver 2.3 Jan 24 15:30:06 volumio671hht kernel: Bluetooth: HCI UART protocol H4 registered Jan 24 15:30:06 volumio671hht kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Jan 24 15:30:06 volumio671hht kernel: Bluetooth: HCI UART protocol Broadcom registered Jan 24 15:30:06 volumio671hht systemd[1]: Starting Load/Save RF Kill Switch Status... Jan 24 15:30:06 volumio671hht systemd[1]: Started Configure Bluetooth Modems connected by UART. Jan 24 15:30:06 volumio671hht systemd[1]: Started Load/Save RF Kill Switch Status. Jan 24 15:30:06 volumio671hht systemd[1]: Created slice system-bthelper.slice. Jan 24 15:30:06 volumio671hht systemd[1]: Starting Raspberry Pi bluetooth helper... Jan 24 15:30:06 volumio671hht bthelper[685]: Can't init device hci0: Operation not possible due to RF-kill (132) Jan 24 15:30:06 volumio671hht systemd[1]: bthelper@hci0.service: Main process exited, code=exited, status=1/FAILURE Jan 24 15:30:06 volumio671hht systemd[1]: bthelper@hci0.service: Failed with result 'exit-code'. Jan 24 15:30:06 volumio671hht systemd[1]: Failed to start Raspberry Pi bluetooth helper. Jan 24 15:30:06 volumio671hht systemd[1]: Starting Bluetooth service... Jan 24 15:30:06 volumio671hht bluetoothd[687]: Bluetooth daemon 5.50 Jan 24 15:30:06 volumio671hht bluetoothd[687]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Jan 24 15:30:06 volumio671hht systemd[1]: Started Bluetooth service. Jan 24 15:30:06 volumio671hht systemd[1]: Reached target Bluetooth. Jan 24 15:30:06 volumio671hht bluetoothd[687]: Starting SDP server Jan 24 15:30:06 volumio671hht bluetoothd[687]: Excluding (cli) sap Jan 24 15:30:06 volumio671hht bluetoothd[687]: Bluetooth management interface 1.18 initialized Jan 24 15:30:06 volumio671hht dbus-daemon[463]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=687 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Jan 24 15:30:06 volumio671hht kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Jan 24 15:30:06 volumio671hht kernel: Bluetooth: BNEP filters: protocol multicast Jan 24 15:30:06 volumio671hht kernel: Bluetooth: BNEP socket layer initialized Jan 24 15:30:06 volumio671hht bluetoothd[687]: Failed to set mode: Blocked through rfkill (0x12) Jan 24 15:30:06 volumio671hht systemd[1]: Starting Hostname Service... Jan 24 15:30:06 volumio671hht dbus-daemon[463]: [system] Successfully activated service 'org.freedesktop.hostname1' Jan 24 15:30:06 volumio671hht systemd[1]: Started Hostname Service. Jan 24 15:30:06 volumio671hht volumio[645]: info: Loading plugin "network"... Jan 24 15:30:06 volumio671hht volumio[645]: info: Refreshing Cached IP Addresses Jan 24 15:30:06 volumio671hht sudo[691]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 24 15:30:06 volumio671hht sudo[691]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:06 volumio671hht volumio[645]: info: Loading plugin "services"... Jan 24 15:30:06 volumio671hht sudo[691]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:06 volumio671hht volumio[645]: info: Loading plugin "alsa_controller"... Jan 24 15:30:06 volumio671hht sudo[693]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 24 15:30:06 volumio671hht sudo[693]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:06 volumio671hht sudo[693]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:06 volumio671hht volumio[645]: info: Loading plugin "wizard"... Jan 24 15:30:06 volumio671hht volumio[645]: info: Loading plugin "volumio_command_line_client"... Jan 24 15:30:07 volumio671hht volumio[645]: info: Loading plugin "upnp"... Jan 24 15:30:07 volumio671hht volumio[645]: info: [1674574207005] Starting Upmpd Daemon Jan 24 15:30:07 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 24 15:30:07 volumio671hht volumio[645]: info: Loading plugin "my_music"... Jan 24 15:30:07 volumio671hht volumio[645]: info: Loading plugin "mpd"... Jan 24 15:30:07 volumio671hht volumio[645]: info: Creating MPD Configuration file Jan 24 15:30:07 volumio671hht volumio[645]: info: Loading plugin "upnp_browser"... Jan 24 15:30:07 volumio671hht sudo[699]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 24 15:30:07 volumio671hht sudo[699]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:07 volumio671hht sudo[699]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:07 volumio671hht sudo[701]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 24 15:30:07 volumio671hht sudo[701]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:07 volumio671hht systemd[1]: Stopping Music Player Daemon... Jan 24 15:30:07 volumio671hht systemd[1]: mpd.service: Succeeded. Jan 24 15:30:07 volumio671hht systemd[1]: Stopped Music Player Daemon. Jan 24 15:30:07 volumio671hht systemd[1]: Starting Music Player Daemon... Jan 24 15:30:07 volumio671hht volumio[645]: info: Loading plugin "networkfs"... Jan 24 15:30:08 volumio671hht volumio[645]: info: Starting Udev Watcher for removable devices Jan 24 15:30:08 volumio671hht sudo[709]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.103/Music /mnt/NAS/Nas Jan 24 15:30:08 volumio671hht sudo[709]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:08 volumio671hht kernel: FS-Cache: Netfs 'cifs' registered for caching Jan 24 15:30:08 volumio671hht sudo[709]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:08 volumio671hht kernel: Key type cifs.spnego registered Jan 24 15:30:08 volumio671hht kernel: Key type cifs.idmap registered Jan 24 15:30:08 volumio671hht kernel: CIFS: Attempting to mount //192.168.1.103/Music Jan 24 15:30:08 volumio671hht 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. Jan 24 15:30:08 volumio671hht kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Jan 24 15:30:08 volumio671hht kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Jan 24 15:30:08 volumio671hht mpd[706]: Jan 24 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 24 15:30:08 volumio671hht volumio[645]: info: Ignoring mount for partition: boot Jan 24 15:30:08 volumio671hht volumio[645]: info: Ignoring mount for partition: volumio Jan 24 15:30:08 volumio671hht volumio[645]: info: Ignoring mount for partition: volumio_data Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "alarm-clock"... Jan 24 15:30:08 volumio671hht mpd[706]: Jan 24 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jan 24 15:30:08 volumio671hht mpd[706]: Jan 24 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jan 24 15:30:08 volumio671hht systemd[1]: Started Music Player Daemon. Jan 24 15:30:08 volumio671hht sudo[701]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "airplay_emulation"... Jan 24 15:30:08 volumio671hht volumio[645]: info: Starting Shairport Sync Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "last_100"... Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "webradio"... Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "i2s_dacs"... Jan 24 15:30:08 volumio671hht volumio[645]: info: I2S DAC not set, start Auto-detection Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "volumiodiscovery"... Jan 24 15:30:08 volumio671hht volumio[645]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 24 15:30:08 volumio671hht volumio[645]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 24 15:30:08 volumio671hht node[645]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 24 15:30:08 volumio671hht volumio[645]: *** WARNING *** For more information see Jan 24 15:30:08 volumio671hht volumio[645]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 24 15:30:08 volumio671hht volumio[645]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 24 15:30:08 volumio671hht volumio[645]: *** WARNING *** For more information see Jan 24 15:30:08 volumio671hht node[645]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 24 15:30:08 volumio671hht node[645]: *** WARNING *** For more information see Jan 24 15:30:08 volumio671hht node[645]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 24 15:30:08 volumio671hht node[645]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 24 15:30:08 volumio671hht node[645]: *** WARNING *** For more information see Jan 24 15:30:08 volumio671hht volumio[645]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 24 15:30:08 volumio671hht volumio[645]: info: Discovery: Started advertising with name: Volumio671hht Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "outputs"... Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "albumart"... Jan 24 15:30:08 volumio671hht volumio[645]: info: Plugin example_plugin is not enabled Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "inputs"... Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "updater_comm"... Jan 24 15:30:08 volumio671hht volumio[645]: info: Plugin mpdemulation is not enabled Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "rest_api"... Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading plugin "websocket"... Jan 24 15:30:08 volumio671hht volumio[645]: info: Loading i18n strings for locale vi Jan 24 15:30:08 volumio671hht volumio[645]: Updating browse sources language Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::initPlayerControls Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:08 volumio671hht volumio[645]: Forking 3 albumart workers Jan 24 15:30:08 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 24 15:30:08 volumio671hht volumio[645]: Express server listening on port 3000 Jan 24 15:30:08 volumio671hht volumio[645]: [Metrics] WebUI: 4s 804.06ms Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreStateMachine::resetVolumioState Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreStateMachine::getcurrentVolume Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::volumioRetrievevolume Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: Cannot mount NAS Nas at system boot, trial number 1 ,retrying in 5 seconds Jan 24 15:30:09 volumio671hht volumio[645]: info: MPD Permissions set Jan 24 15:30:09 volumio671hht volumio-remote-updater[450]: [2023-01-24 15:30:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1674574205 101 Jan 24 15:30:09 volumio671hht volumio[645]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreStateMachine::pushState Jan 24 15:30:09 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPushState Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreStateMachine::updateTrackBlock Jan 24 15:30:09 volumio671hht volumio[645]: info: CorePlayQueue::getTrackBlock Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::volumioRetrievevolume Jan 24 15:30:09 volumio671hht volumio[645]: info: MPD running with PID706 Jan 24 15:30:09 volumio671hht volumio[645]: ,establishing connection Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: Reloading queue from file Jan 24 15:30:09 volumio671hht volumio[645]: error: updateQueue error: null Jan 24 15:30:09 volumio671hht volumio[645]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 24 15:30:09 volumio671hht volumio[645]: info: Setting Device type: Raspberry PI Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreStateMachine::setRepeat true single undefined Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreStateMachine::pushState Jan 24 15:30:09 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPushState Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreStateMachine::setRandom true Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreStateMachine::pushState Jan 24 15:30:09 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPushState Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreStateMachine::pushState Jan 24 15:30:09 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPushState Jan 24 15:30:09 volumio671hht volumio[645]: info: Completed loading Core Plugins Jan 24 15:30:09 volumio671hht volumio[645]: info: Preparing to generate the ALSA configuration file Jan 24 15:30:09 volumio671hht volumio[645]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 24 15:30:09 volumio671hht volumio[645]: info: Reading ALSA contributions from plugins. Jan 24 15:30:09 volumio671hht volumio[645]: info: Asound.conf file unchanged, so no further update is needed Jan 24 15:30:09 volumio671hht volumio[645]: info: Output device has changed, restarting MPD Jan 24 15:30:09 volumio671hht volumio[645]: info: Output device has changed, restarting Shairport Sync Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 24 15:30:09 volumio671hht sudo[779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 24 15:30:09 volumio671hht sudo[779]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:09 volumio671hht sudo[779]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:09 volumio671hht sudo[780]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 24 15:30:09 volumio671hht sudo[780]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:09 volumio671hht systemd[1]: Stopping Music Player Daemon... Jan 24 15:30:09 volumio671hht volumio[645]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 24 15:30:09 volumio671hht volumio[645]: info: ___________ START PLUGINS ___________ Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 24 15:30:09 volumio671hht volumio[645]: info: [1674574209625] CoreMusicLibrary::Adding element Media Servers Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 24 15:30:09 volumio671hht systemd[1]: mpd.service: Succeeded. Jan 24 15:30:09 volumio671hht systemd[1]: Stopped Music Player Daemon. Jan 24 15:30:09 volumio671hht systemd[1]: Starting Music Player Daemon... Jan 24 15:30:09 volumio671hht volumio[645]: Cannot find translation for sourceMedia Servers Jan 24 15:30:09 volumio671hht volumio[645]: Starting albumart workers Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: Starting albumart workers Jan 24 15:30:09 volumio671hht volumio[645]: Starting albumart workers Jan 24 15:30:09 volumio671hht volumio[645]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 24 15:30:09 volumio671hht volumio[645]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 24 15:30:09 volumio671hht volumio[645]: info: [1674574209838] CoreMusicLibrary::Adding element Last_100 Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 24 15:30:09 volumio671hht volumio[645]: Cannot find translation for sourceMedia Servers Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 24 15:30:09 volumio671hht volumio[645]: info: [1674574209841] CoreMusicLibrary::Adding element Webradio Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 24 15:30:09 volumio671hht volumio[645]: Cannot find translation for sourceMedia Servers Jan 24 15:30:09 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 24 15:30:09 volumio671hht volumio[645]: info: Volumio Calling Home Jan 24 15:30:10 volumio671hht volumio[645]: info: Completed starting Core Plugins Jan 24 15:30:10 volumio671hht volumio[645]: info: ------------------------------------------- Jan 24 15:30:10 volumio671hht volumio[645]: info: ----- MyVolumio plugins startup ---- Jan 24 15:30:10 volumio671hht volumio[645]: info: ------------------------------------------- Jan 24 15:30:10 volumio671hht volumio[645]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 24 15:30:10 volumio671hht sh[373]: eth0: leased 192.168.1.199 for 86400 seconds Jan 24 15:30:10 volumio671hht sh[373]: eth0: adding route to 192.168.1.0/24 Jan 24 15:30:10 volumio671hht sh[373]: eth0: adding default route via 192.168.1.1 Jan 24 15:30:10 volumio671hht dhcpcd[417]: eth0: leased 192.168.1.199 for 86400 seconds Jan 24 15:30:10 volumio671hht avahi-daemon[468]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.199. Jan 24 15:30:10 volumio671hht avahi-daemon[468]: New relevant interface eth0.IPv4 for mDNS. Jan 24 15:30:10 volumio671hht dhcpcd[417]: eth0: adding route to 192.168.1.0/24 Jan 24 15:30:10 volumio671hht avahi-daemon[468]: Registering new address record for 192.168.1.199 on eth0.IPv4. Jan 24 15:30:10 volumio671hht dhcpcd[417]: eth0: adding default route via 192.168.1.1 Jan 24 15:30:10 volumio671hht volumio[645]: Unhandled rejection Error: No sockets available, cannot start. Jan 24 15:30:10 volumio671hht volumio[645]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Jan 24 15:30:10 volumio671hht volumio[645]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Jan 24 15:30:10 volumio671hht volumio[645]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Jan 24 15:30:10 volumio671hht volumio[645]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Jan 24 15:30:10 volumio671hht volumio[645]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Jan 24 15:30:10 volumio671hht volumio[645]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Jan 24 15:30:10 volumio671hht volumio[645]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Jan 24 15:30:10 volumio671hht volumio[645]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Jan 24 15:30:10 volumio671hht volumio[645]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Jan 24 15:30:10 volumio671hht volumio[645]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Jan 24 15:30:10 volumio671hht volumio[645]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Jan 24 15:30:10 volumio671hht volumio[645]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jan 24 15:30:10 volumio671hht volumio[645]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jan 24 15:30:10 volumio671hht volumio[645]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Jan 24 15:30:10 volumio671hht volumio[645]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Jan 24 15:30:10 volumio671hht volumio[645]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jan 24 15:30:10 volumio671hht volumio[645]: error: MPD error: Error: write EPIPE Jan 24 15:30:10 volumio671hht volumio[645]: info: MPD Permissions set Jan 24 15:30:10 volumio671hht sh[373]: forked to background, child pid 818 Jan 24 15:30:10 volumio671hht dhcpcd[417]: forked to background, child pid 818 Jan 24 15:30:10 volumio671hht volumio[645]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:10 volumio671hht volumio[645]: info: Starting Shairport Sync Jan 24 15:30:10 volumio671hht volumio[645]: info: Starting Shairport Sync Jan 24 15:30:10 volumio671hht volumio[645]: info: Starting Shairport Sync Jan 24 15:30:10 volumio671hht sudo[852]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 24 15:30:10 volumio671hht sudo[852]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:10 volumio671hht sudo[860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 24 15:30:10 volumio671hht sudo[860]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:10 volumio671hht ifplugd(eth0)[617]: client: ifup: interface eth0 already configured Jan 24 15:30:10 volumio671hht sh[373]: eth0=eth0 Jan 24 15:30:10 volumio671hht systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 24 15:30:10 volumio671hht systemd[1]: shairport-sync.service: Succeeded. Jan 24 15:30:10 volumio671hht systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 24 15:30:10 volumio671hht systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 24 15:30:10 volumio671hht sudo[852]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:10 volumio671hht sudo[860]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:10 volumio671hht sudo[881]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 24 15:30:10 volumio671hht sudo[881]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:10 volumio671hht ifplugd(eth0)[617]: Program executed successfully. Jan 24 15:30:10 volumio671hht systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 24 15:30:10 volumio671hht systemd[1]: shairport-sync.service: Succeeded. Jan 24 15:30:10 volumio671hht systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 24 15:30:10 volumio671hht systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 24 15:30:10 volumio671hht sudo[881]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:10 volumio671hht volumio[645]: info: Shairport-Sync Started Jan 24 15:30:10 volumio671hht volumio[645]: Error adding Membership: Error: addMembership EINVAL Jan 24 15:30:10 volumio671hht volumio[645]: info: Shairport-Sync Started Jan 24 15:30:10 volumio671hht volumio[645]: info: Shairport-Sync Started Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:10 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:10 volumio671hht mpd[794]: Jan 24 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 24 15:30:10 volumio671hht mpd[794]: Jan 24 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jan 24 15:30:10 volumio671hht mpd[794]: Jan 24 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jan 24 15:30:10 volumio671hht systemd[1]: Started Music Player Daemon. Jan 24 15:30:10 volumio671hht sudo[780]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:10 volumio671hht volumio[645]: error: updateQueue error: null Jan 24 15:30:10 volumio671hht volumio[645]: info: Discovery: adding 7c6ef65f-c4bb-40d9-a43d-a8df109741a3 Jan 24 15:30:10 volumio671hht volumio[645]: info: mDNS: Found device Volumio671hht Jan 24 15:30:10 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:10 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 24 15:30:11 volumio671hht volumio[645]: info: Discovery: Getting this device information Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:11 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 24 15:30:11 volumio671hht volumio[645]: verbose: New Socket.io Connection to 192.168.1.199:3000 from 192.168.1.238 UA: Dart/3.9 (dart:io) Total Clients: 3 Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 24 15:30:11 volumio671hht volumio[645]: verbose: New Socket.io Connection to 192.168.1.199:3000 from 192.168.1.238 UA: Dart/3.9 (dart:io) Total Clients: 3 Jan 24 15:30:11 volumio671hht volumio[645]: verbose: New Socket.io Connection to 192.168.1.199:3000 from 192.168.1.238 UA: Dart/3.9 (dart:io) Total Clients: 4 Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 24 15:30:11 volumio671hht volumio[645]: info: Discovery: Getting this device information Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:11 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 24 15:30:11 volumio671hht volumio[645]: info: Discovery: Getting this device information Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:11 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:11 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 24 15:30:11 volumio671hht systemd[1]: systemd-rfkill.service: Succeeded. Jan 24 15:30:11 volumio671hht ntpd[610]: Listen normally on 3 eth0 192.168.1.199:123 Jan 24 15:30:11 volumio671hht ntpd[610]: new interface(s) found: waking up resolver Jan 24 15:30:12 volumio671hht nmbd[596]: [2023/01/24 15:30:12.121711, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 24 15:30:12 volumio671hht systemd[1]: Started Samba NMB Daemon. Jan 24 15:30:12 volumio671hht nmbd[596]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jan 24 15:30:12 volumio671hht systemd[1]: Starting Samba Winbind Daemon... Jan 24 15:30:12 volumio671hht winbindd[889]: [2023/01/24 15:30:12.318114, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jan 24 15:30:12 volumio671hht winbindd[889]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jan 24 15:30:12 volumio671hht winbindd[889]: [2023/01/24 15:30:12.336423, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 24 15:30:12 volumio671hht winbindd[889]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jan 24 15:30:12 volumio671hht systemd[1]: Started Samba Winbind Daemon. Jan 24 15:30:12 volumio671hht systemd[1]: Starting Samba SMB Daemon... Jan 24 15:30:12 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 24 15:30:12 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 24 15:30:12 volumio671hht volumio[645]: info: Discovery: Getting this device information Jan 24 15:30:12 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:12 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:12 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 24 15:30:12 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 24 15:30:12 volumio671hht winbindd[889]: [2023/01/24 15:30:12.661827, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Jan 24 15:30:12 volumio671hht winbindd[889]: res_names->count = 1, expected 2 Jan 24 15:30:12 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Jan 24 15:30:12 volumio671hht smbd[894]: [2023/01/24 15:30:12.683363, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 24 15:30:12 volumio671hht smbd[894]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jan 24 15:30:12 volumio671hht systemd[1]: Started Samba SMB Daemon. Jan 24 15:30:12 volumio671hht systemd[1]: Reached target Multi-User System. Jan 24 15:30:12 volumio671hht systemd[1]: Reached target Graphical Interface. Jan 24 15:30:12 volumio671hht systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 24 15:30:12 volumio671hht systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 24 15:30:12 volumio671hht systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 24 15:30:12 volumio671hht systemd[1]: Startup finished in 9.501s (kernel) + 21.347s (userspace) = 30.848s. Jan 24 15:30:13 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 24 15:30:13 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 24 15:30:13 volumio671hht volumio[645]: info: Discovery: Getting this device information Jan 24 15:30:13 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:13 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:13 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 24 15:30:13 volumio671hht volumio[645]: verbose: New Socket.io Connection to 192.168.1.199:3000 from 192.168.1.238 UA: Dart/3.9 (dart:io) Total Clients: 4 Jan 24 15:30:13 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 24 15:30:13 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 24 15:30:14 volumio671hht sudo[904]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.103/Music /mnt/NAS/Nas Jan 24 15:30:14 volumio671hht sudo[904]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:14 volumio671hht kernel: CIFS: Attempting to mount //192.168.1.103/Music Jan 24 15:30:15 volumio671hht kernel: cam-dummy-reg: disabling Jan 24 15:30:15 volumio671hht kernel: cam1-reg: disabling Jan 24 15:30:15 volumio671hht volumio[645]: error: updateQueue error: null Jan 24 15:30:17 volumio671hht sudo[909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 24 15:30:17 volumio671hht sudo[909]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:17 volumio671hht sudo[909]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:17 volumio671hht sudo[911]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 24 15:30:17 volumio671hht sudo[911]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:17 volumio671hht sudo[911]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:17 volumio671hht sudo[915]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 24 15:30:17 volumio671hht sudo[915]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:17 volumio671hht systemd[1]: Started UPnP Renderer front-end to MPD. Jan 24 15:30:17 volumio671hht sudo[915]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:17 volumio671hht volumio[645]: info: Upmpdcli Daemon Started Jan 24 15:30:17 volumio671hht volumio[917]: Generating RSA private key, 4096 bit long modulus (2 primes) Jan 24 15:30:17 volumio671hht volumio[917]: ..++++ Jan 24 15:30:20 volumio671hht volumio[645]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.251&uuid=9d30e3a2885cf06c8f26835da5713a45" http://updates.volumio.org/downloader-v1/track-device Jan 24 15:30:20 volumio671hht volumio[645]: % Total % Received % Xferd Average Speed Time Time Time Current Jan 24 15:30:20 volumio671hht volumio[645]: Dload Upload Total Spent Left Speed Jan 24 15:30:20 volumio671hht volumio[645]: [132B blob data] Jan 24 15:30:20 volumio671hht volumio[645]: retrying in 5 seconds, trial 0 Jan 24 15:30:20 volumio671hht volumio[645]: info: Volumio Calling Home Jan 24 15:30:20 volumio671hht sudo[904]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:20 volumio671hht volumio[645]: info: Cannot mount NAS Nas at system boot, trial number 2 ,retrying in 5 seconds Jan 24 15:30:20 volumio671hht kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Jan 24 15:30:20 volumio671hht kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Jan 24 15:30:20 volumio671hht volumio[645]: info: Volumio called home Jan 24 15:30:21 volumio671hht volumio[917]: ......................................++++ Jan 24 15:30:21 volumio671hht volumio[917]: e is 65537 (0x010001) Jan 24 15:30:21 volumio671hht volumio[917]: writing RSA key Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jan 24 15:30:22 volumio671hht sudo[952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jan 24 15:30:22 volumio671hht sudo[952]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:22 volumio671hht sudo[957]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 24 15:30:22 volumio671hht sudo[957]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:22 volumio671hht sudo[952]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:22 volumio671hht sudo[957]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:22 volumio671hht sudo[964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 24 15:30:22 volumio671hht sudo[964]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:22 volumio671hht sudo[964]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:22 volumio671hht sudo[972]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 24 15:30:22 volumio671hht sudo[972]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:22 volumio671hht sudo[977]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 24 15:30:22 volumio671hht sudo[977]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:22 volumio671hht sudo[972]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:22 volumio671hht sudo[977]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:22 volumio671hht sudo[980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 24 15:30:22 volumio671hht sudo[980]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:22 volumio671hht sudo[980]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 24 15:30:22 volumio671hht volumio[645]: info: Discovery: Getting this device information Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:22 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 24 15:30:22 volumio671hht volumio[645]: info: Discovery: Getting this device information Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:22 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:22 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 24 15:30:22 volumio671hht volumio[645]: verbose: New Socket.io Connection to 192.168.1.199:3000 from 192.168.1.238 UA: Dart/3.9 (dart:io) Total Clients: 4 Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 24 15:30:22 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 24 15:30:24 volumio671hht sudo[984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 24 15:30:24 volumio671hht sudo[984]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:24 volumio671hht sudo[984]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:24 volumio671hht sudo[986]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 24 15:30:24 volumio671hht sudo[986]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:24 volumio671hht sudo[986]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:24 volumio671hht volumio[645]: verbose: New Socket.io Connection to 192.168.1.199 from 192.168.1.238 UA: Mozilla/5.0 (Linux; Android 15; 23129RAA4G Build/AQ3A.240829.003; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Total Clients: 4 Jan 24 15:30:25 volumio671hht sudo[990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 24 15:30:25 volumio671hht sudo[990]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:25 volumio671hht sudo[990]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:25 volumio671hht sudo[992]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 24 15:30:25 volumio671hht sudo[992]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:25 volumio671hht sudo[992]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:25 volumio671hht sudo[996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.103/Music /mnt/NAS/Nas Jan 24 15:30:25 volumio671hht sudo[996]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:25 volumio671hht volumio[645]: verbose: New Socket.io Connection to 192.168.1.199 from 192.168.1.238 UA: Mozilla/5.0 (Linux; Android 15; 23129RAA4G Build/AQ3A.240829.003; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Total Clients: 5 Jan 24 15:30:25 volumio671hht kernel: CIFS: Attempting to mount //192.168.1.103/Music Jan 24 15:30:25 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:25 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:25 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 24 15:30:25 volumio671hht volumio[645]: info: Listing playlists Jan 24 15:30:25 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 24 15:30:25 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 24 15:30:25 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 24 15:30:25 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 24 15:30:27 volumio671hht systemd[1]: systemd-fsckd.service: Succeeded. Jan 24 15:30:30 volumio671hht volumio[645]: error: MyVolumio Plugin failed to start in a timely fashion Jan 24 15:30:30 volumio671hht volumio[645]: info: BOOT COMPLETED Jan 24 15:30:30 volumio671hht volumio[645]: [Metrics] CommandRouter: 25s 229.49ms Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::volumiosetStartupVolume Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::Close All Modals sent Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::Close All Modals sent Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPlay Jan 24 15:30:30 volumio671hht volumio[645]: verbose: UNSET VOLATILE Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::play index undefined Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 24 15:30:30 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::startPlaybackTimer Jan 24 15:30:30 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::clearAddPlayTracks NAS/Nas/02.Hòa tấu - Nhạc không lời/MUSIC FOR CHIDREN/Unknown album (11-6-2016 6-49-37 PM) 01 Track 1 922kbps.flac Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::sendMpdCommand stop Jan 24 15:30:30 volumio671hht volumio[645]: info: sendMpdCommand stop took 2 milliseconds Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::sendMpdCommand clear Jan 24 15:30:30 volumio671hht volumio[645]: info: sendMpdCommand clear took 1 milliseconds Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::sendMpdCommand add "NAS/Nas/02.Hòa tấu - Nhạc không lời/MUSIC FOR CHIDREN/Unknown album (11-6-2016 6-49-37 PM) 01 Track 1 922kbps.flac" Jan 24 15:30:30 volumio671hht volumio[645]: info: Jan 24 15:30:30 volumio671hht volumio[645]: ---------------------------- MPD announces system playlist update Jan 24 15:30:30 volumio671hht volumio[645]: info: Ignoring MPD Status Update Jan 24 15:30:30 volumio671hht volumio[645]: info: Jan 24 15:30:30 volumio671hht volumio[645]: ---------------------------- MPD announces system playlist update Jan 24 15:30:30 volumio671hht volumio[645]: info: Ignoring MPD Status Update Jan 24 15:30:30 volumio671hht volumio[645]: info: sendMpdCommand add "NAS/Nas/02.Hòa tấu - Nhạc không lời/MUSIC FOR CHIDREN/Unknown album (11-6-2016 6-49-37 PM) 01 Track 1 922kbps.flac" took 3 milliseconds Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::sendMpdCommand play Jan 24 15:30:30 volumio671hht volumio[645]: info: Jan 24 15:30:30 volumio671hht volumio[645]: ---------------------------- MPD announces system playlist update Jan 24 15:30:30 volumio671hht volumio[645]: info: Ignoring MPD Status Update Jan 24 15:30:30 volumio671hht volumio[645]: info: ------------------------------ 7ms Jan 24 15:30:30 volumio671hht volumio[645]: info: ------------------------------ 6ms Jan 24 15:30:30 volumio671hht volumio[645]: info: sendMpdCommand play took 5 milliseconds Jan 24 15:30:30 volumio671hht volumio[645]: info: ------------------------------ 4ms Jan 24 15:30:30 volumio671hht volumio[645]: info: Jan 24 15:30:30 volumio671hht volumio[645]: ---------------------------- MPD announces system playlist update Jan 24 15:30:30 volumio671hht volumio[645]: info: Ignoring MPD Status Update Jan 24 15:30:30 volumio671hht volumio[645]: info: Jan 24 15:30:30 volumio671hht volumio[645]: ---------------------------- MPD announces state update: player Jan 24 15:30:30 volumio671hht volumio[645]: info: ControllerMpd::getState Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::sendMpdCommand status Jan 24 15:30:30 volumio671hht volumio[645]: info: ------------------------------ 2ms Jan 24 15:30:30 volumio671hht volumio[645]: info: Jan 24 15:30:30 volumio671hht volumio[645]: ---------------------------- MPD announces state update: player Jan 24 15:30:30 volumio671hht volumio[645]: info: ControllerMpd::getState Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::sendMpdCommand status Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::sendMpdCommand clearerror Jan 24 15:30:30 volumio671hht volumio[645]: info: sendMpdCommand status took 12 milliseconds Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::sendMpdCommand clearerror Jan 24 15:30:30 volumio671hht volumio[645]: info: sendMpdCommand status took 12 milliseconds Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::parseState Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::parseState Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 24 15:30:30 volumio671hht volumio[645]: info: sendMpdCommand clearerror took 7 milliseconds Jan 24 15:30:30 volumio671hht volumio[645]: info: sendMpdCommand clearerror took 6 milliseconds Jan 24 15:30:30 volumio671hht volumio[645]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 24 15:30:30 volumio671hht volumio[645]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::parseTrackInfo Jan 24 15:30:30 volumio671hht volumio[645]: verbose: ControllerMpd::parseTrackInfo Jan 24 15:30:30 volumio671hht volumio[645]: info: ControllerMpd::pushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::servicePushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::pushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:30 volumio671hht volumio[645]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Track 1","artist":"Unknown artist","album":"Unknown album (11/6/2016 6:49:37 PM)","uri":"NAS/Nas/02.Hòa tấu - Nhạc không lời/MUSIC FOR CHIDREN/Unknown album (11-6-2016 6-49-37 PM) 01 Track 1 922kbps.flac","trackType":"flac"} Jan 24 15:30:30 volumio671hht volumio[645]: verbose: CURRENT POSITION 0 Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::syncState stateService stop Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::syncState currentStatus stop Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::pushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPushState Jan 24 15:30:30 volumio671hht volumio[645]: info: No code Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::pushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPushState Jan 24 15:30:30 volumio671hht volumio[645]: info: ControllerMpd::pushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::servicePushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::pushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:30 volumio671hht volumio[645]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Track 1","artist":"Unknown artist","album":"Unknown album (11/6/2016 6:49:37 PM)","uri":"NAS/Nas/02.Hòa tấu - Nhạc không lời/MUSIC FOR CHIDREN/Unknown album (11-6-2016 6-49-37 PM) 01 Track 1 922kbps.flac","trackType":"flac"} Jan 24 15:30:30 volumio671hht volumio[645]: verbose: CURRENT POSITION 0 Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::syncState stateService stop Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::syncState currentStatus stop Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::pushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPushState Jan 24 15:30:30 volumio671hht volumio[645]: info: No code Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreStateMachine::pushState Jan 24 15:30:30 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:30 volumio671hht volumio[645]: info: CoreCommandRouter::volumioPushState Jan 24 15:30:30 volumio671hht volumio[645]: info: ------------------------------ 61ms Jan 24 15:30:30 volumio671hht volumio[645]: info: ------------------------------ 60ms Jan 24 15:30:31 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 24 15:30:31 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 24 15:30:31 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 24 15:30:31 volumio671hht sudo[996]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:31 volumio671hht volumio[645]: info: Cannot mount NAS Nas at system boot, trial number 3 ,retrying in 5 seconds Jan 24 15:30:31 volumio671hht kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Jan 24 15:30:31 volumio671hht kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Jan 24 15:30:36 volumio671hht systemd[1]: systemd-hostnamed.service: Succeeded. Jan 24 15:30:36 volumio671hht sudo[1017]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.103/Music /mnt/NAS/Nas Jan 24 15:30:36 volumio671hht sudo[1017]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:36 volumio671hht kernel: CIFS: Attempting to mount //192.168.1.103/Music Jan 24 15:30:37 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 24 15:30:37 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 24 15:30:37 volumio671hht sudo[1022]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 24 15:30:37 volumio671hht sudo[1022]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:37 volumio671hht sudo[1022]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:37 volumio671hht sudo[1024]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 24 15:30:37 volumio671hht sudo[1024]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:37 volumio671hht sudo[1024]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:37 volumio671hht volumio[645]: verbose: New Socket.io Connection to 192.168.1.199 from 192.168.1.238 UA: Mozilla/5.0 (Linux; Android 15; 23129RAA4G Build/AQ3A.240829.003; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Total Clients: 5 Jan 24 15:30:38 volumio671hht sudo[1028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 24 15:30:38 volumio671hht sudo[1028]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:38 volumio671hht sudo[1028]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:38 volumio671hht sudo[1030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 24 15:30:38 volumio671hht sudo[1030]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 24 15:30:38 volumio671hht sudo[1030]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:38 volumio671hht volumio[645]: verbose: New Socket.io Connection to 192.168.1.199 from 192.168.1.238 UA: Mozilla/5.0 (Linux; Android 15; 23129RAA4G Build/AQ3A.240829.003; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Total Clients: 6 Jan 24 15:30:38 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetState Jan 24 15:30:38 volumio671hht volumio[645]: info: CorePlayQueue::getTrack 0 Jan 24 15:30:38 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 24 15:30:38 volumio671hht volumio[645]: info: Listing playlists Jan 24 15:30:38 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 24 15:30:38 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 24 15:30:38 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 24 15:30:38 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 24 15:30:39 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetVisibleSources Jan 24 15:30:39 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 24 15:30:39 volumio671hht volumio[645]: info: CoreCommandRouter::volumioGetQueue Jan 24 15:30:39 volumio671hht volumio[645]: info: CoreStateMachine::getQueue Jan 24 15:30:39 volumio671hht volumio[645]: info: CorePlayQueue::getQueue Jan 24 15:30:39 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 24 15:30:39 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 24 15:30:42 volumio671hht sudo[1017]: pam_unix(sudo:session): session closed for user root Jan 24 15:30:42 volumio671hht volumio[645]: info: Cannot mount NAS Nas at system boot, trial number 4 ,retrying in 5 seconds Jan 24 15:30:43 volumio671hht kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Jan 24 15:30:43 volumio671hht kernel: CIFS: VFS: cifs_mount failed w/return code = -113 Jan 24 15:30:43 volumio671hht volumio[645]: info: CoreCommandRouter::executeOnPlugin: last_100 , handleBrowseUri Jan 24 15:30:43 volumio671hht volumio[645]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 24 15:30:43 volumio671hht volumio[645]: Error: certificate is not yet valid Jan 24 15:30:43 volumio671hht volumio[645]: at TLSSocket.onConnectSecure (_tls_wrap.js:1497:34) Jan 24 15:30:43 volumio671hht volumio[645]: at TLSSocket.emit (events.js:315:20) Jan 24 15:30:43 volumio671hht volumio[645]: at TLSSocket._finishInit (_tls_wrap.js:932:8) Jan 24 15:30:43 volumio671hht volumio[645]: at TLSWrap.ssl.onhandshakedone (_tls_wrap.js:706:12) { Jan 24 15:30:43 volumio671hht volumio[645]: code: 'CERT_NOT_YET_VALID' Jan 24 15:30:43 volumio671hht volumio[645]: } Jan 24 15:30:43 volumio671hht volumio[645]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 24 15:30:44 volumio671hht sudo[1048]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2023-01-24 15:29 Jan 24 15:30:44 volumio671hht sudo[1048]: 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="1c5fa5a8788b087ca429be9d10851b25c5cc4f5b" VOLUMIO_FE_VERSION="e5ce74e254a237ac98580c4437c4ed223c7d5cd9" VOLUMIO_FE3_VERSION="a86adf3c7ed2d6c50d9bca768f58ab2f56832dc1" VOLUMIO_BE_VERSION="c8882d89d3d4e0a1571e0dc9701741128f5a1656" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 31 Mar 2022 02:51:41 PM CEST" VOLUMIO_VERSION="3.251" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e83cc5fcd68eb3ee4105ab0b8b3779ea"