-- Logs begin at Sun 2025-06-01 22:31:43 CEST, end at Sun 2025-06-01 22:31:59 CEST. -- Jun 01 22:31:43 volumio3 kernel: Booting Linux on physical CPU 0x0000000000 [0x414fd0b1] Jun 01 22:31:43 volumio3 kernel: Linux version 6.6.62-v8+ (dom@buildbot) (aarch64-linux-gnu-gcc (Ubuntu 11.4.0-1ubuntu1~22.04) 11.4.0, GNU ld (GNU Binutils for Ubuntu) 2.38) #1816 SMP PREEMPT Mon Nov 18 15:35:52 GMT 2024 Jun 01 22:31:43 volumio3 kernel: KASLR enabled Jun 01 22:31:43 volumio3 kernel: random: crng init done Jun 01 22:31:43 volumio3 kernel: Machine model: Raspberry Pi 5 Model B Rev 1.0 Jun 01 22:31:43 volumio3 kernel: efi: UEFI not found. Jun 01 22:31:43 volumio3 kernel: Reserved memory: created CMA memory pool at 0x0000000001c00000, size 64 MiB Jun 01 22:31:43 volumio3 kernel: OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool Jun 01 22:31:43 volumio3 kernel: OF: reserved mem: 0x0000000001c00000..0x0000000005bfffff (65536 KiB) map reusable linux,cma Jun 01 22:31:43 volumio3 kernel: OF: reserved mem: 0x0000000000000000..0x000000000007ffff (512 KiB) nomap non-reusable atf@0 Jun 01 22:31:43 volumio3 kernel: OF: reserved mem: 0x000000003fd16200..0x000000003fd16237 (0 KiB) nomap non-reusable nvram@0 Jun 01 22:31:43 volumio3 kernel: NUMA: No NUMA configuration found Jun 01 22:31:43 volumio3 kernel: Faking a node at [mem 0x0000000000000000-0x000000003fffffff] Jun 01 22:31:43 volumio3 kernel: Faking a node at [mem 0x0000000040000000-0x000000007fffffff] Jun 01 22:31:43 volumio3 kernel: Faking a node at [mem 0x0000000080000000-0x00000000bfffffff] Jun 01 22:31:43 volumio3 kernel: Faking a node at [mem 0x00000000c0000000-0x00000000ffffffff] Jun 01 22:31:43 volumio3 kernel: Faking a node at [mem 0x0000000100000000-0x000000013fffffff] Jun 01 22:31:43 volumio3 kernel: Faking a node at [mem 0x0000000140000000-0x000000017fffffff] Jun 01 22:31:43 volumio3 kernel: Faking a node at [mem 0x0000000180000000-0x00000001bfffffff] Jun 01 22:31:43 volumio3 kernel: Faking a node at [mem 0x00000001c0000000-0x00000001ffffffff] Jun 01 22:31:43 volumio3 kernel: NUMA: NODE_DATA [mem 0x3f7fd3c0-0x3f7fffff] Jun 01 22:31:43 volumio3 kernel: NUMA: NODE_DATA [mem 0x7fffd3c0-0x7fffffff] Jun 01 22:31:43 volumio3 kernel: NUMA: NODE_DATA [mem 0xbfffd3c0-0xbfffffff] Jun 01 22:31:43 volumio3 kernel: NUMA: NODE_DATA [mem 0xffffd3c0-0xffffffff] Jun 01 22:31:43 volumio3 kernel: NUMA: NODE_DATA [mem 0x13fffd3c0-0x13fffffff] Jun 01 22:31:43 volumio3 kernel: NUMA: NODE_DATA [mem 0x17fffd3c0-0x17fffffff] Jun 01 22:31:43 volumio3 kernel: NUMA: NODE_DATA [mem 0x1bfffd3c0-0x1bfffffff] Jun 01 22:31:43 volumio3 kernel: NUMA: NODE_DATA [mem 0x1fef973c0-0x1fef99fff] Jun 01 22:31:43 volumio3 kernel: Zone ranges: Jun 01 22:31:43 volumio3 kernel: DMA [mem 0x0000000000000000-0x00000000ffffffff] Jun 01 22:31:43 volumio3 kernel: DMA32 empty Jun 01 22:31:43 volumio3 kernel: Normal [mem 0x0000000100000000-0x00000001ffffffff] Jun 01 22:31:43 volumio3 kernel: Movable zone start for each node Jun 01 22:31:43 volumio3 kernel: Early memory node ranges Jun 01 22:31:43 volumio3 kernel: node 0: [mem 0x0000000000000000-0x000000000007ffff] Jun 01 22:31:43 volumio3 kernel: node 0: [mem 0x0000000000080000-0x000000003f7fffff] Jun 01 22:31:43 volumio3 kernel: node 1: [mem 0x0000000040000000-0x000000007fffffff] Jun 01 22:31:43 volumio3 kernel: node 2: [mem 0x0000000080000000-0x00000000bfffffff] Jun 01 22:31:43 volumio3 kernel: node 3: [mem 0x00000000c0000000-0x00000000ffffffff] Jun 01 22:31:43 volumio3 kernel: node 4: [mem 0x0000000100000000-0x000000013fffffff] Jun 01 22:31:43 volumio3 kernel: node 5: [mem 0x0000000140000000-0x000000017fffffff] Jun 01 22:31:43 volumio3 kernel: node 6: [mem 0x0000000180000000-0x00000001bfffffff] Jun 01 22:31:43 volumio3 kernel: node 7: [mem 0x00000001c0000000-0x00000001ffffffff] Jun 01 22:31:43 volumio3 kernel: Initmem setup node 0 [mem 0x0000000000000000-0x000000003f7fffff] Jun 01 22:31:43 volumio3 kernel: Initmem setup node 1 [mem 0x0000000040000000-0x000000007fffffff] Jun 01 22:31:43 volumio3 kernel: Initmem setup node 2 [mem 0x0000000080000000-0x00000000bfffffff] Jun 01 22:31:43 volumio3 kernel: Initmem setup node 3 [mem 0x00000000c0000000-0x00000000ffffffff] Jun 01 22:31:43 volumio3 kernel: Initmem setup node 4 [mem 0x0000000100000000-0x000000013fffffff] Jun 01 22:31:43 volumio3 kernel: Initmem setup node 5 [mem 0x0000000140000000-0x000000017fffffff] Jun 01 22:31:43 volumio3 kernel: Initmem setup node 6 [mem 0x0000000180000000-0x00000001bfffffff] Jun 01 22:31:43 volumio3 kernel: Initmem setup node 7 [mem 0x00000001c0000000-0x00000001ffffffff] Jun 01 22:31:43 volumio3 kernel: On node 1, zone DMA: 2048 pages in unavailable ranges Jun 01 22:31:43 volumio3 kernel: psci: probing for conduit method from DT. Jun 01 22:31:43 volumio3 kernel: psci: PSCIv1.1 detected in firmware. Jun 01 22:31:43 volumio3 kernel: psci: Using standard PSCI v0.2 function IDs Jun 01 22:31:43 volumio3 kernel: psci: MIGRATE_INFO_TYPE not supported. Jun 01 22:31:43 volumio3 kernel: psci: SMC Calling Convention v1.2 Jun 01 22:31:43 volumio3 kernel: percpu: Embedded 30 pages/cpu s85928 r8192 d28760 u122880 Jun 01 22:31:43 volumio3 kernel: pcpu-alloc: s85928 r8192 d28760 u122880 alloc=30*4096 Jun 01 22:31:43 volumio3 kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Jun 01 22:31:43 volumio3 kernel: Detected PIPT I-cache on CPU0 Jun 01 22:31:43 volumio3 kernel: CPU features: detected: Virtualization Host Extensions Jun 01 22:31:43 volumio3 kernel: CPU features: detected: Hardware dirty bit management Jun 01 22:31:43 volumio3 kernel: CPU features: detected: Spectre-v4 Jun 01 22:31:43 volumio3 kernel: CPU features: detected: Spectre-BHB Jun 01 22:31:43 volumio3 kernel: CPU features: kernel page table isolation forced ON by KASLR Jun 01 22:31:43 volumio3 kernel: CPU features: detected: Kernel page table isolation (KPTI) Jun 01 22:31:43 volumio3 kernel: CPU features: detected: SSBS not fully self-synchronizing Jun 01 22:31:43 volumio3 kernel: alternatives: applying boot alternatives Jun 01 22:31:43 volumio3 kernel: Kernel command line: reboot=w coherent_pool=1M 8250.nr_uarts=1 pci=pcie_bus_safe cgroup_disable=memory numa_policy=interleave numa=fake=8 system_heap.max_order=0 smsc95xx.macaddr=2C:CF:67:8C:50:FB vc_mem.mem_base=0x3fc00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyAMA10,115200 console=tty1 imgpart=UUID=e158ce43-90a0-4ed1-b254-0bcaf0c26091 imgfile=/volumio_current.sqsh bootpart=UUID=1B7B-9109 datapart=UUID=39856909-6eb0-448c-982b-aeb1888091d2 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Jun 01 22:31:43 volumio3 kernel: cgroup: Disabling memory control group subsystem Jun 01 22:31:43 volumio3 kernel: mempolicy: NUMA default policy overridden to 'interleave:0-7' Jun 01 22:31:43 volumio3 kernel: PCIe ASPM is disabled Jun 01 22:31:43 volumio3 kernel: Unknown kernel command line parameters "splash nodebug imgpart=UUID=e158ce43-90a0-4ed1-b254-0bcaf0c26091 imgfile=/volumio_current.sqsh bootpart=UUID=1B7B-9109 datapart=UUID=39856909-6eb0-448c-982b-aeb1888091d2 uuidconfig=cmdline.txt bootdelay=7 use_kmsg=no", will be passed to user space. Jun 01 22:31:43 volumio3 kernel: Fallback order for Node 0: 0 1 2 3 4 5 6 7 Jun 01 22:31:43 volumio3 kernel: Fallback order for Node 1: 1 2 3 4 5 6 7 0 Jun 01 22:31:43 volumio3 kernel: Fallback order for Node 2: 2 3 4 5 6 7 0 1 Jun 01 22:31:43 volumio3 kernel: Fallback order for Node 3: 3 4 5 6 7 0 1 2 Jun 01 22:31:43 volumio3 kernel: Fallback order for Node 4: 4 5 6 7 0 1 2 3 Jun 01 22:31:43 volumio3 kernel: Fallback order for Node 5: 5 6 7 0 1 2 3 4 Jun 01 22:31:43 volumio3 kernel: Fallback order for Node 6: 6 7 0 1 2 3 4 5 Jun 01 22:31:43 volumio3 kernel: Fallback order for Node 7: 7 0 1 2 3 4 5 6 Jun 01 22:31:43 volumio3 kernel: Built 8 zonelists, mobility grouping on. Total pages: 2062368 Jun 01 22:31:43 volumio3 kernel: Policy zone: Normal Jun 01 22:31:43 volumio3 kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Jun 01 22:31:43 volumio3 kernel: software IO TLB: area num 4. Jun 01 22:31:43 volumio3 kernel: software IO TLB: mapped [mem 0x00000000fae00000-0x00000000fee00000] (64MB) Jun 01 22:31:43 volumio3 kernel: Memory: 8045400K/8380416K available (13440K kernel code, 2208K rwdata, 4284K rodata, 4864K init, 1086K bss, 269480K reserved, 65536K cma-reserved) Jun 01 22:31:43 volumio3 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=8 Jun 01 22:31:43 volumio3 kernel: ftrace: allocating 43555 entries in 171 pages Jun 01 22:31:43 volumio3 kernel: ftrace: allocated 171 pages with 5 groups Jun 01 22:31:43 volumio3 kernel: trace event string verifier disabled Jun 01 22:31:43 volumio3 kernel: rcu: Preemptible hierarchical RCU implementation. Jun 01 22:31:43 volumio3 kernel: rcu: RCU event tracing is enabled. Jun 01 22:31:43 volumio3 kernel: rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4. Jun 01 22:31:43 volumio3 kernel: Trampoline variant of Tasks RCU enabled. Jun 01 22:31:43 volumio3 kernel: Rude variant of Tasks RCU enabled. Jun 01 22:31:43 volumio3 kernel: Tracing variant of Tasks RCU enabled. Jun 01 22:31:43 volumio3 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. Jun 01 22:31:43 volumio3 kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 Jun 01 22:31:43 volumio3 kernel: NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 Jun 01 22:31:43 volumio3 kernel: Root IRQ handler: gic_handle_irq Jun 01 22:31:43 volumio3 kernel: GIC: Using split EOI/Deactivate mode Jun 01 22:31:43 volumio3 kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Jun 01 22:31:43 volumio3 kernel: arch_timer: cp15 timer(s) running at 54.00MHz (phys). Jun 01 22:31:43 volumio3 kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns Jun 01 22:31:43 volumio3 kernel: sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns Jun 01 22:31:43 volumio3 kernel: Console: colour dummy device 80x25 Jun 01 22:31:43 volumio3 kernel: printk: console [tty1] enabled Jun 01 22:31:43 volumio3 kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000) Jun 01 22:31:43 volumio3 kernel: pid_max: default: 32768 minimum: 301 Jun 01 22:31:43 volumio3 kernel: LSM: initializing lsm=capability,integrity Jun 01 22:31:43 volumio3 kernel: Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Jun 01 22:31:43 volumio3 kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Jun 01 22:31:43 volumio3 kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Jun 01 22:31:43 volumio3 kernel: rcu: Hierarchical SRCU implementation. Jun 01 22:31:43 volumio3 kernel: rcu: Max phase no-delay instances is 1000. Jun 01 22:31:43 volumio3 kernel: EFI services will not be available. Jun 01 22:31:43 volumio3 kernel: smp: Bringing up secondary CPUs ... Jun 01 22:31:43 volumio3 kernel: Detected PIPT I-cache on CPU1 Jun 01 22:31:43 volumio3 kernel: CPU1: Booted secondary processor 0x0000000100 [0x414fd0b1] Jun 01 22:31:43 volumio3 kernel: Detected PIPT I-cache on CPU2 Jun 01 22:31:43 volumio3 kernel: CPU2: Booted secondary processor 0x0000000200 [0x414fd0b1] Jun 01 22:31:43 volumio3 kernel: Detected PIPT I-cache on CPU3 Jun 01 22:31:43 volumio3 kernel: CPU3: Booted secondary processor 0x0000000300 [0x414fd0b1] Jun 01 22:31:43 volumio3 kernel: smp: Brought up 8 nodes, 4 CPUs Jun 01 22:31:43 volumio3 kernel: SMP: Total of 4 processors activated. Jun 01 22:31:43 volumio3 kernel: CPU features: detected: 32-bit EL0 Support Jun 01 22:31:43 volumio3 kernel: CPU features: detected: Data cache clean to the PoU not required for I/D coherence Jun 01 22:31:43 volumio3 kernel: CPU features: detected: Common not Private translations Jun 01 22:31:43 volumio3 kernel: CPU features: detected: CRC32 instructions Jun 01 22:31:43 volumio3 kernel: CPU features: detected: RCpc load-acquire (LDAPR) Jun 01 22:31:43 volumio3 kernel: CPU features: detected: LSE atomic instructions Jun 01 22:31:43 volumio3 kernel: CPU features: detected: Privileged Access Never Jun 01 22:31:43 volumio3 kernel: CPU features: detected: RAS Extension Support Jun 01 22:31:43 volumio3 kernel: CPU features: detected: Speculative Store Bypassing Safe (SSBS) Jun 01 22:31:43 volumio3 kernel: CPU: All CPU(s) started at EL2 Jun 01 22:31:43 volumio3 kernel: alternatives: applying system-wide alternatives Jun 01 22:31:43 volumio3 kernel: devtmpfs: initialized Jun 01 22:31:43 volumio3 kernel: Enabled cp15_barrier support Jun 01 22:31:43 volumio3 kernel: Enabled setend support Jun 01 22:31:43 volumio3 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns Jun 01 22:31:43 volumio3 kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: pinctrl core: initialized pinctrl subsystem Jun 01 22:31:43 volumio3 kernel: DMI not present or invalid. Jun 01 22:31:43 volumio3 kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Jun 01 22:31:43 volumio3 kernel: DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations Jun 01 22:31:43 volumio3 kernel: DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations Jun 01 22:31:43 volumio3 kernel: DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations Jun 01 22:31:43 volumio3 kernel: audit: initializing netlink subsys (disabled) Jun 01 22:31:43 volumio3 kernel: audit: type=2000 audit(0.008:1): state=initialized audit_enabled=0 res=1 Jun 01 22:31:43 volumio3 kernel: thermal_sys: Registered thermal governor 'step_wise' Jun 01 22:31:43 volumio3 kernel: cpuidle: using governor menu Jun 01 22:31:43 volumio3 kernel: hw-breakpoint: found 6 breakpoint and 4 watchpoint registers. Jun 01 22:31:43 volumio3 kernel: ASID allocator initialised with 32768 entries Jun 01 22:31:43 volumio3 kernel: Serial: AMBA PL011 UART driver Jun 01 22:31:43 volumio3 kernel: bcm2835-mbox 107c013880.mailbox: mailbox enabled Jun 01 22:31:43 volumio3 kernel: 107d001000.serial: ttyAMA10 at MMIO 0x107d001000 (irq = 15, base_baud = 0) is a PL011 rev2 Jun 01 22:31:43 volumio3 kernel: printk: console [ttyAMA10] enabled Jun 01 22:31:43 volumio3 kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2025-03-10T17:10:37, variant start_cd Jun 01 22:31:43 volumio3 kernel: raspberrypi-firmware soc:firmware: Firmware hash is 2bb2ae6400000000000000000000000000000000 Jun 01 22:31:43 volumio3 kernel: Modules: 2G module region forced by RANDOMIZE_MODULE_REGION_FULL Jun 01 22:31:43 volumio3 kernel: Modules: 0 pages in range for non-PLT usage Jun 01 22:31:43 volumio3 kernel: Modules: 517776 pages in range for PLT usage Jun 01 22:31:43 volumio3 kernel: bcm2835-dma 1000010000.dma: DMA legacy API manager, dmachans=0x1 Jun 01 22:31:43 volumio3 kernel: iommu: Default domain type: Translated Jun 01 22:31:43 volumio3 kernel: iommu: DMA domain TLB invalidation policy: strict mode Jun 01 22:31:43 volumio3 kernel: SCSI subsystem initialized Jun 01 22:31:43 volumio3 kernel: usbcore: registered new interface driver usbfs Jun 01 22:31:43 volumio3 kernel: usbcore: registered new interface driver hub Jun 01 22:31:43 volumio3 kernel: usbcore: registered new device driver usb Jun 01 22:31:43 volumio3 kernel: pps_core: LinuxPPS API ver. 1 registered Jun 01 22:31:43 volumio3 kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti Jun 01 22:31:43 volumio3 kernel: PTP clock support registered Jun 01 22:31:43 volumio3 kernel: vgaarb: loaded Jun 01 22:31:43 volumio3 kernel: clocksource: Switched to clocksource arch_sys_counter Jun 01 22:31:43 volumio3 kernel: VFS: Disk quotas dquot_6.6.0 Jun 01 22:31:43 volumio3 kernel: VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Jun 01 22:31:43 volumio3 kernel: FS-Cache: Loaded Jun 01 22:31:43 volumio3 kernel: CacheFiles: Loaded Jun 01 22:31:43 volumio3 kernel: NET: Registered PF_INET protocol family Jun 01 22:31:43 volumio3 kernel: IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: tcp_listen_portaddr_hash hash table entries: 4096 (order: 4, 65536 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: TCP: Hash tables configured (established 65536 bind 65536) Jun 01 22:31:43 volumio3 kernel: MPTCP token hash table entries: 8192 (order: 5, 196608 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: UDP hash table entries: 4096 (order: 5, 131072 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes, vmalloc) Jun 01 22:31:43 volumio3 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Jun 01 22:31:43 volumio3 kernel: RPC: Registered named UNIX socket transport module. Jun 01 22:31:43 volumio3 kernel: RPC: Registered udp transport module. Jun 01 22:31:43 volumio3 kernel: RPC: Registered tcp transport module. Jun 01 22:31:43 volumio3 kernel: RPC: Registered tcp-with-tls transport module. Jun 01 22:31:43 volumio3 kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Jun 01 22:31:43 volumio3 kernel: PCI: CLS 0 bytes, default 64 Jun 01 22:31:43 volumio3 kernel: Trying to unpack rootfs image as initramfs... Jun 01 22:31:43 volumio3 kernel: kvm [1]: IPA Size Limit: 40 bits Jun 01 22:31:43 volumio3 kernel: kvm [1]: vgic interrupt IRQ9 Jun 01 22:31:43 volumio3 kernel: kvm [1]: VHE mode initialized successfully Jun 01 22:31:43 volumio3 kernel: Initialise system trusted keyrings Jun 01 22:31:43 volumio3 kernel: workingset: timestamp_bits=42 max_order=21 bucket_order=0 Jun 01 22:31:43 volumio3 kernel: zbud: loaded Jun 01 22:31:43 volumio3 kernel: NFS: Registering the id_resolver key type Jun 01 22:31:43 volumio3 kernel: Key type id_resolver registered Jun 01 22:31:43 volumio3 kernel: Key type id_legacy registered Jun 01 22:31:43 volumio3 kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Jun 01 22:31:43 volumio3 kernel: nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Jun 01 22:31:43 volumio3 kernel: Key type asymmetric registered Jun 01 22:31:43 volumio3 kernel: Asymmetric key parser 'x509' registered Jun 01 22:31:43 volumio3 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) Jun 01 22:31:43 volumio3 kernel: io scheduler mq-deadline registered Jun 01 22:31:43 volumio3 kernel: io scheduler kyber registered Jun 01 22:31:43 volumio3 kernel: io scheduler bfq registered Jun 01 22:31:43 volumio3 kernel: irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7c502000, parent irq: 26) Jun 01 22:31:43 volumio3 kernel: irq_brcmstb_l2: registered L2 intc (/soc/intc@7d503000, parent irq: 27) Jun 01 22:31:43 volumio3 kernel: irq_brcmstb_l2: registered L2 intc (/soc/intc@7d508380, parent irq: 28) Jun 01 22:31:43 volumio3 kernel: irq_brcmstb_l2: registered L2 intc (/soc/intc@7d508400, parent irq: 29) Jun 01 22:31:43 volumio3 kernel: irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7d510600, parent irq: 30) Jun 01 22:31:43 volumio3 kernel: irq_brcmstb_l2: registered L2 intc (/soc/intc@7d517b00, parent irq: 31) Jun 01 22:31:43 volumio3 kernel: simple-framebuffer 3f800000.framebuffer: framebuffer at 0x3f800000, 0x3f4800 bytes Jun 01 22:31:43 volumio3 kernel: simple-framebuffer 3f800000.framebuffer: format=r5g6b5, mode=1920x1080x16, linelength=3840 Jun 01 22:31:43 volumio3 kernel: Console: switching to colour frame buffer device 240x67 Jun 01 22:31:43 volumio3 kernel: simple-framebuffer 3f800000.framebuffer: fb0: simplefb registered! Jun 01 22:31:43 volumio3 kernel: Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled Jun 01 22:31:43 volumio3 kernel: Freeing initrd memory: 28084K Jun 01 22:31:43 volumio3 kernel: 107d50c000.serial: ttyS0 at MMIO 0x107d50c000 (irq = 33, base_baud = 6000000) is a Broadcom BCM7271 UART Jun 01 22:31:43 volumio3 kernel: serial serial0: tty port ttyS0 registered Jun 01 22:31:43 volumio3 kernel: iproc-rng200 107d208000.rng: hwrng registered Jun 01 22:31:43 volumio3 kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3fc00000 mem_size:0x40000000(1024 MiB) Jun 01 22:31:43 volumio3 kernel: bcm2712-iommu-cache 1000005b00.iommuc: bcm2712_iommu_cache_probe Jun 01 22:31:43 volumio3 kernel: brd: module loaded Jun 01 22:31:43 volumio3 kernel: loop: module loaded Jun 01 22:31:43 volumio3 kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Jun 01 22:31:43 volumio3 kernel: Loading iSCSI transport class v2.0-870. Jun 01 22:31:43 volumio3 kernel: usbcore: registered new device driver r8152-cfgselector Jun 01 22:31:43 volumio3 kernel: usbcore: registered new interface driver r8152 Jun 01 22:31:43 volumio3 kernel: usbcore: registered new interface driver lan78xx Jun 01 22:31:43 volumio3 kernel: usbcore: registered new interface driver smsc95xx Jun 01 22:31:43 volumio3 kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Jun 01 22:31:43 volumio3 kernel: dwc_otg: FIQ enabled Jun 01 22:31:43 volumio3 kernel: dwc_otg: NAK holdoff enabled Jun 01 22:31:43 volumio3 kernel: dwc_otg: FIQ split-transaction FSM enabled Jun 01 22:31:43 volumio3 kernel: Module dwc_common_port init Jun 01 22:31:43 volumio3 kernel: usbcore: registered new interface driver uas Jun 01 22:31:43 volumio3 kernel: usbcore: registered new interface driver usb-storage Jun 01 22:31:43 volumio3 kernel: mousedev: PS/2 mouse device common for all mice Jun 01 22:31:43 volumio3 kernel: rpi-rtc soc:rpi_rtc: registered as rtc0 Jun 01 22:31:43 volumio3 kernel: rpi-rtc soc:rpi_rtc: setting system clock to 2025-06-01T20:31:32 UTC (1748809892) Jun 01 22:31:43 volumio3 kernel: bcm2835-wdt bcm2835-wdt: Poweroff handler already present! Jun 01 22:31:43 volumio3 kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Jun 01 22:31:43 volumio3 kernel: sdhci: Secure Digital Host Controller Interface driver Jun 01 22:31:43 volumio3 kernel: sdhci: Copyright(c) Pierre Ossman Jun 01 22:31:43 volumio3 kernel: sdhci-pltfm: SDHCI platform and OF driver helper Jun 01 22:31:43 volumio3 kernel: ledtrig-cpu: registered to indicate activity on CPUs Jun 01 22:31:43 volumio3 kernel: SMCCC: SOC_ID: ARCH_SOC_ID not implemented, skipping .... Jun 01 22:31:43 volumio3 kernel: hid: raw HID events driver (C) Jiri Kosina Jun 01 22:31:43 volumio3 kernel: usbcore: registered new interface driver usbhid Jun 01 22:31:43 volumio3 kernel: usbhid: USB HID core driver Jun 01 22:31:43 volumio3 kernel: hw perfevents: enabled with armv8_cortex_a76 PMU driver, 7 counters available Jun 01 22:31:43 volumio3 kernel: NET: Registered PF_PACKET protocol family Jun 01 22:31:43 volumio3 kernel: Key type dns_resolver registered Jun 01 22:31:43 volumio3 kernel: registered taskstats version 1 Jun 01 22:31:43 volumio3 kernel: Loading compiled-in X.509 certificates Jun 01 22:31:43 volumio3 kernel: Key type .fscrypt registered Jun 01 22:31:43 volumio3 kernel: Key type fscrypt-provisioning registered Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000110000.pcie: host bridge /axi/pcie@110000 ranges: Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000110000.pcie: No bus range found for /axi/pcie@110000, using [bus 00-ff] Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000110000.pcie: MEM 0x1b80000000..0x1bffffffff -> 0x0080000000 Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000110000.pcie: MEM 0x1800000000..0x1b7fffffff -> 0x0400000000 Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000110000.pcie: IB MEM 0x0000000000..0x0fffffffff -> 0x1000000000 Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000110000.pcie: Forcing gen 2 Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000110000.pcie: PCI host bridge to bus 0000:00 Jun 01 22:31:43 volumio3 kernel: pci_bus 0000:00: Unknown NUMA node; performance will be reduced Jun 01 22:31:43 volumio3 kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Jun 01 22:31:43 volumio3 kernel: pci_bus 0000:00: root bus resource [mem 0x1b80000000-0x1bffffffff] (bus address [0x80000000-0xffffffff]) Jun 01 22:31:43 volumio3 kernel: pci_bus 0000:00: root bus resource [mem 0x1800000000-0x1b7fffffff pref] (bus address [0x400000000-0x77fffffff]) Jun 01 22:31:43 volumio3 kernel: pci 0000:00:00.0: [14e4:2712] type 01 class 0x060400 Jun 01 22:31:43 volumio3 kernel: pci 0000:00:00.0: PME# supported from D0 D3hot Jun 01 22:31:43 volumio3 kernel: pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000110000.pcie: link up, 5.0 GT/s PCIe x1 (!SSC) Jun 01 22:31:43 volumio3 kernel: pci 0000:01:00.0: [c0a9:540a] type 00 class 0x010802 Jun 01 22:31:43 volumio3 kernel: pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00003fff 64bit] Jun 01 22:31:43 volumio3 kernel: pci 0000:01:00.0: 4.000 Gb/s available PCIe bandwidth, limited by 5.0 GT/s PCIe x1 link at 0000:00:00.0 (capable of 31.504 Gb/s with 8.0 GT/s PCIe x4 link) Jun 01 22:31:43 volumio3 kernel: pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01 Jun 01 22:31:43 volumio3 kernel: pci 0000:00:00.0: BAR 8: assigned [mem 0x1b80000000-0x1b800fffff] Jun 01 22:31:43 volumio3 kernel: pci 0000:01:00.0: BAR 0: assigned [mem 0x1b80000000-0x1b80003fff 64bit] Jun 01 22:31:43 volumio3 kernel: pci 0000:00:00.0: PCI bridge to [bus 01] Jun 01 22:31:43 volumio3 kernel: pci 0000:00:00.0: bridge window [mem 0x1b80000000-0x1b800fffff] Jun 01 22:31:43 volumio3 kernel: pci 0000:00:00.0: Max Payload Size set to 512/ 512 (was 128), Max Read Rq 512 Jun 01 22:31:43 volumio3 kernel: pci 0000:01:00.0: Max Payload Size set to 512/ 512 (was 128), Max Read Rq 512 Jun 01 22:31:43 volumio3 kernel: pcieport 0000:00:00.0: enabling device (0000 -> 0002) Jun 01 22:31:43 volumio3 kernel: pcieport 0000:00:00.0: PME: Signaling with IRQ 38 Jun 01 22:31:43 volumio3 kernel: pcieport 0000:00:00.0: AER: enabled with IRQ 38 Jun 01 22:31:43 volumio3 kernel: nvme nvme0: pci function 0000:01:00.0 Jun 01 22:31:43 volumio3 kernel: nvme 0000:01:00.0: enabling device (0000 -> 0002) Jun 01 22:31:43 volumio3 kernel: nvme nvme0: missing or invalid SUBNQN field. Jun 01 22:31:43 volumio3 kernel: hwmon hwmon1: temp1_input not attached to any thermal zone Jun 01 22:31:43 volumio3 kernel: hwmon hwmon1: temp2_input not attached to any thermal zone Jun 01 22:31:43 volumio3 kernel: hwmon hwmon1: temp3_input not attached to any thermal zone Jun 01 22:31:43 volumio3 kernel: hwmon hwmon1: temp9_input not attached to any thermal zone Jun 01 22:31:43 volumio3 kernel: nvme nvme0: allocated 32 MiB host memory buffer. Jun 01 22:31:43 volumio3 kernel: nvme nvme0: 4/0/0 default/read/poll queues Jun 01 22:31:43 volumio3 kernel: nvme nvme0: Ignoring bogus Namespace Identifiers Jun 01 22:31:43 volumio3 kernel: nvme0n1: p1 p2 p3 Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000120000.pcie: host bridge /axi/pcie@120000 ranges: Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000120000.pcie: No bus range found for /axi/pcie@120000, using [bus 00-ff] Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000120000.pcie: MEM 0x1f00000000..0x1ffffffffb -> 0x0000000000 Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000120000.pcie: MEM 0x1c00000000..0x1effffffff -> 0x0400000000 Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000120000.pcie: IB MEM 0x1f00000000..0x1f003fffff -> 0x0000000000 Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000120000.pcie: IB MEM 0x0000000000..0x0fffffffff -> 0x1000000000 Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000120000.pcie: Forcing gen 2 Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000120000.pcie: PCI host bridge to bus 0001:00 Jun 01 22:31:43 volumio3 kernel: pci_bus 0001:00: Unknown NUMA node; performance will be reduced Jun 01 22:31:43 volumio3 kernel: pci_bus 0001:00: root bus resource [bus 00-ff] Jun 01 22:31:43 volumio3 kernel: pci_bus 0001:00: root bus resource [mem 0x1f00000000-0x1ffffffffb] (bus address [0x00000000-0xfffffffb]) Jun 01 22:31:43 volumio3 kernel: pci_bus 0001:00: root bus resource [mem 0x1c00000000-0x1effffffff pref] (bus address [0x400000000-0x6ffffffff]) Jun 01 22:31:43 volumio3 kernel: pci 0001:00:00.0: [14e4:2712] type 01 class 0x060400 Jun 01 22:31:43 volumio3 kernel: pci 0001:00:00.0: PME# supported from D0 D3hot Jun 01 22:31:43 volumio3 kernel: pci 0001:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring Jun 01 22:31:43 volumio3 kernel: brcm-pcie 1000120000.pcie: link up, 5.0 GT/s PCIe x4 (!SSC) Jun 01 22:31:43 volumio3 kernel: pci 0001:01:00.0: [1de4:0001] type 00 class 0x020000 Jun 01 22:31:43 volumio3 kernel: pci 0001:01:00.0: reg 0x10: [mem 0xffffc000-0xffffffff] Jun 01 22:31:43 volumio3 kernel: pci 0001:01:00.0: reg 0x14: [mem 0xffc00000-0xffffffff] Jun 01 22:31:43 volumio3 kernel: pci 0001:01:00.0: reg 0x18: [mem 0xffff0000-0xffffffff] Jun 01 22:31:43 volumio3 kernel: pci 0001:01:00.0: supports D1 Jun 01 22:31:43 volumio3 kernel: pci 0001:01:00.0: PME# supported from D0 D1 D3hot D3cold Jun 01 22:31:43 volumio3 kernel: pci_bus 0001:01: busn_res: [bus 01-ff] end is updated to 01 Jun 01 22:31:43 volumio3 kernel: pci 0001:00:00.0: BAR 8: assigned [mem 0x1f00000000-0x1f005fffff] Jun 01 22:31:43 volumio3 kernel: pci 0001:01:00.0: BAR 1: assigned [mem 0x1f00000000-0x1f003fffff] Jun 01 22:31:43 volumio3 kernel: pci 0001:01:00.0: BAR 2: assigned [mem 0x1f00400000-0x1f0040ffff] Jun 01 22:31:43 volumio3 kernel: pci 0001:01:00.0: BAR 0: assigned [mem 0x1f00410000-0x1f00413fff] Jun 01 22:31:43 volumio3 kernel: pci 0001:00:00.0: PCI bridge to [bus 01] Jun 01 22:31:43 volumio3 kernel: pci 0001:00:00.0: bridge window [mem 0x1f00000000-0x1f005fffff] Jun 01 22:31:43 volumio3 kernel: pci 0001:00:00.0: Max Payload Size set to 256/ 512 (was 128), Max Read Rq 512 Jun 01 22:31:43 volumio3 kernel: pci 0001:01:00.0: Max Payload Size set to 256/ 256 (was 128), Max Read Rq 512 Jun 01 22:31:43 volumio3 kernel: pcieport 0001:00:00.0: enabling device (0000 -> 0002) Jun 01 22:31:43 volumio3 kernel: pcieport 0001:00:00.0: PME: Signaling with IRQ 44 Jun 01 22:31:43 volumio3 kernel: pcieport 0001:00:00.0: AER: enabled with IRQ 44 Jun 01 22:31:43 volumio3 kernel: rp1 0001:01:00.0: bar0 len 0x4000, start 0x1f00410000, end 0x1f00413fff, flags, 0x40200 Jun 01 22:31:43 volumio3 kernel: rp1 0001:01:00.0: bar1 len 0x400000, start 0x1f00000000, end 0x1f003fffff, flags, 0x40200 Jun 01 22:31:43 volumio3 kernel: rp1 0001:01:00.0: enabling device (0000 -> 0002) Jun 01 22:31:43 volumio3 kernel: rp1 0001:01:00.0: chip_id 0x20001927 Jun 01 22:31:43 volumio3 kernel: genirq: irq_chip rp1_irq_chip did not update eff. affinity mask of irq 106 Jun 01 22:31:43 volumio3 kernel: macb 1f00100000.ethernet eth0: Cadence GEM rev 0x00070109 at 0x1f00100000 irq 112 (2c:cf:67:8c:50:fb) Jun 01 22:31:43 volumio3 kernel: dw_axi_dmac_platform 1f00188000.dma: DesignWare AXI DMA Controller, 8 channels Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.0: xHCI Host Controller Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.0: new USB bus registered, assigned bus number 1 Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.0: hcc params 0x0240fe6d hci version 0x110 quirks 0x0000008000000810 Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.0: irq 137, io mem 0x1f00200000 Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.0: xHCI Host Controller Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.0: new USB bus registered, assigned bus number 2 Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.0: Host supports USB 3.0 SuperSpeed Jun 01 22:31:43 volumio3 kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06 Jun 01 22:31:43 volumio3 kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Jun 01 22:31:43 volumio3 kernel: usb usb1: Product: xHCI Host Controller Jun 01 22:31:43 volumio3 kernel: usb usb1: Manufacturer: Linux 6.6.62-v8+ xhci-hcd Jun 01 22:31:43 volumio3 kernel: usb usb1: SerialNumber: xhci-hcd.0 Jun 01 22:31:43 volumio3 kernel: hub 1-0:1.0: USB hub found Jun 01 22:31:43 volumio3 kernel: hub 1-0:1.0: 2 ports detected Jun 01 22:31:43 volumio3 kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.06 Jun 01 22:31:43 volumio3 kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Jun 01 22:31:43 volumio3 kernel: usb usb2: Product: xHCI Host Controller Jun 01 22:31:43 volumio3 kernel: usb usb2: Manufacturer: Linux 6.6.62-v8+ xhci-hcd Jun 01 22:31:43 volumio3 kernel: usb usb2: SerialNumber: xhci-hcd.0 Jun 01 22:31:43 volumio3 kernel: hub 2-0:1.0: USB hub found Jun 01 22:31:43 volumio3 kernel: hub 2-0:1.0: 1 port detected Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.1: xHCI Host Controller Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.1: new USB bus registered, assigned bus number 3 Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.1: hcc params 0x0240fe6d hci version 0x110 quirks 0x0000008000000810 Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.1: irq 142, io mem 0x1f00300000 Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.1: xHCI Host Controller Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.1: new USB bus registered, assigned bus number 4 Jun 01 22:31:43 volumio3 kernel: xhci-hcd xhci-hcd.1: Host supports USB 3.0 SuperSpeed Jun 01 22:31:43 volumio3 kernel: usb usb3: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06 Jun 01 22:31:43 volumio3 kernel: usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Jun 01 22:31:43 volumio3 kernel: usb usb3: Product: xHCI Host Controller Jun 01 22:31:43 volumio3 kernel: usb usb3: Manufacturer: Linux 6.6.62-v8+ xhci-hcd Jun 01 22:31:43 volumio3 kernel: usb usb3: SerialNumber: xhci-hcd.1 Jun 01 22:31:43 volumio3 kernel: hub 3-0:1.0: USB hub found Jun 01 22:31:43 volumio3 kernel: hub 3-0:1.0: 2 ports detected Jun 01 22:31:43 volumio3 kernel: usb usb4: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.06 Jun 01 22:31:43 volumio3 kernel: usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Jun 01 22:31:43 volumio3 kernel: usb usb4: Product: xHCI Host Controller Jun 01 22:31:43 volumio3 kernel: usb usb4: Manufacturer: Linux 6.6.62-v8+ xhci-hcd Jun 01 22:31:43 volumio3 kernel: usb usb4: SerialNumber: xhci-hcd.1 Jun 01 22:31:43 volumio3 kernel: hub 4-0:1.0: USB hub found Jun 01 22:31:43 volumio3 kernel: hub 4-0:1.0: 1 port detected Jun 01 22:31:43 volumio3 kernel: bcm2712-iommu 1000005100.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774 Jun 01 22:31:43 volumio3 kernel: platform 1000800000.codec: bcm2712_iommu_probe_device: MMU 1000005100.iommu Jun 01 22:31:43 volumio3 kernel: platform 1000800000.codec: bcm2712_iommu_device_group: MMU 1000005100.iommu Jun 01 22:31:43 volumio3 kernel: platform 1000800000.codec: Adding to iommu group 0 Jun 01 22:31:43 volumio3 kernel: platform 1000880000.pisp_be: bcm2712_iommu_probe_device: MMU 1000005100.iommu Jun 01 22:31:43 volumio3 kernel: platform 1000880000.pisp_be: bcm2712_iommu_device_group: MMU 1000005100.iommu Jun 01 22:31:43 volumio3 kernel: platform 1000880000.pisp_be: Adding to iommu group 0 Jun 01 22:31:43 volumio3 kernel: platform 1000800000.codec: bcm2712_iommu_attach_dev: MMU 1000005100.iommu Jun 01 22:31:43 volumio3 kernel: platform 1000880000.pisp_be: bcm2712_iommu_attach_dev: MMU 1000005100.iommu Jun 01 22:31:43 volumio3 kernel: bcm2712-iommu 1000005100.iommu: bcm2712_iommu_probe: Success Jun 01 22:31:43 volumio3 kernel: bcm2712-iommu 1000005200.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774 Jun 01 22:31:43 volumio3 kernel: platform axi:gpu: bcm2712_iommu_probe_device: MMU 1000005200.iommu Jun 01 22:31:43 volumio3 kernel: platform axi:gpu: bcm2712_iommu_device_group: MMU 1000005200.iommu Jun 01 22:31:43 volumio3 kernel: platform axi:gpu: Adding to iommu group 1 Jun 01 22:31:43 volumio3 kernel: platform axi:gpu: bcm2712_iommu_attach_dev: MMU 1000005200.iommu Jun 01 22:31:43 volumio3 kernel: bcm2712-iommu 1000005200.iommu: bcm2712_iommu_probe: Success Jun 01 22:31:43 volumio3 kernel: bcm2712-iommu 1000005280.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774 Jun 01 22:31:43 volumio3 kernel: bcm2712-iommu 1000005280.iommu: bcm2712_iommu_probe: Success Jun 01 22:31:43 volumio3 kernel: sdhci-brcmstb 1000fff000.mmc: Got CD GPIO Jun 01 22:31:43 volumio3 kernel: mmc0: CQHCI version 5.10 Jun 01 22:31:43 volumio3 kernel: mmc1: CQHCI version 5.10 Jun 01 22:31:43 volumio3 kernel: of_cfs_init Jun 01 22:31:43 volumio3 kernel: of_cfs_init: OK Jun 01 22:31:43 volumio3 kernel: clk: Disabling unused clocks Jun 01 22:31:43 volumio3 kernel: mmc0: SDHCI controller on 1000fff000.mmc [1000fff000.mmc] using ADMA 64-bit Jun 01 22:31:43 volumio3 kernel: mmc1: SDHCI controller on 1001100000.mmc [1001100000.mmc] using ADMA 64-bit Jun 01 22:31:43 volumio3 kernel: Freeing unused kernel memory: 4864K Jun 01 22:31:43 volumio3 kernel: Run /init as init process Jun 01 22:31:43 volumio3 kernel: with arguments: Jun 01 22:31:43 volumio3 kernel: /init Jun 01 22:31:43 volumio3 kernel: splash Jun 01 22:31:43 volumio3 kernel: nodebug Jun 01 22:31:43 volumio3 kernel: with environment: Jun 01 22:31:43 volumio3 kernel: HOME=/ Jun 01 22:31:43 volumio3 kernel: TERM=linux Jun 01 22:31:43 volumio3 kernel: imgpart=UUID=e158ce43-90a0-4ed1-b254-0bcaf0c26091 Jun 01 22:31:43 volumio3 kernel: imgfile=/volumio_current.sqsh Jun 01 22:31:43 volumio3 kernel: bootpart=UUID=1B7B-9109 Jun 01 22:31:43 volumio3 kernel: datapart=UUID=39856909-6eb0-448c-982b-aeb1888091d2 Jun 01 22:31:43 volumio3 kernel: uuidconfig=cmdline.txt Jun 01 22:31:43 volumio3 kernel: bootdelay=7 Jun 01 22:31:43 volumio3 kernel: use_kmsg=no Jun 01 22:31:43 volumio3 kernel: mmc1: new ultra high speed DDR50 SDIO card at address 0001 Jun 01 22:31:43 volumio3 kernel: usb 3-1: new high-speed USB device number 2 using xhci-hcd Jun 01 22:31:43 volumio3 kernel: usb 1-1: new full-speed USB device number 2 using xhci-hcd Jun 01 22:31:43 volumio3 kernel: usb 3-1: New USB device found, idVendor=152a, idProduct=85dd, bcdDevice= 3.54 Jun 01 22:31:43 volumio3 kernel: usb 3-1: New USB device strings: Mfr=1, Product=3, SerialNumber=2 Jun 01 22:31:43 volumio3 kernel: usb 3-1: Product: SMSL USB AUDIO Jun 01 22:31:43 volumio3 kernel: usb 3-1: Manufacturer: SMSL Jun 01 22:31:43 volumio3 kernel: usb 1-1: New USB device found, idVendor=222a, idProduct=0001, bcdDevice= 0.02 Jun 01 22:31:43 volumio3 kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Jun 01 22:31:43 volumio3 kernel: usb 1-1: Product: ILITEK-TOUCH Jun 01 22:31:43 volumio3 kernel: usb 1-1: Manufacturer: ILITEK Jun 01 22:31:43 volumio3 kernel: input: ILITEK ILITEK-TOUCH Touchscreen as /devices/platform/axi/1000120000.pcie/1f00200000.usb/xhci-hcd.0/usb1/1-1/1-1:1.0/0003:222A:0001.0002/input/input0 Jun 01 22:31:43 volumio3 kernel: hid-generic 0003:222A:0001.0002: input,hiddev96,hidraw0: USB HID v1.10 Device [ILITEK ILITEK-TOUCH] on usb-xhci-hcd.0-1/input0 Jun 01 22:31:43 volumio3 kernel: hid-generic 0003:152A:85DD.0001: hiddev97,hidraw1: USB HID v1.10 Device [SMSL SMSL USB AUDIO] on usb-xhci-hcd.1-1/input3 Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_info_register (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_info_create_module_entry (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_info_free_entry (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_fasync_helper (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_ecards_limit (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_oss_info_register (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_unregister_device (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_device_alloc (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_device_new (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_fasync_free (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_kill_fasync (err -2) Jun 01 22:31:43 volumio3 kernel: snd_timer: Unknown symbol snd_register_device (err -2) Jun 01 22:31:43 volumio3 kernel: input: pwr_button as /devices/platform/pwr_button/input/input2 Jun 01 22:31:43 volumio3 kernel: brcmstb-i2c 107d508200.i2c: @97500hz registered in interrupt mode Jun 01 22:31:43 volumio3 kernel: brcmstb-i2c 107d508280.i2c: @97500hz registered in interrupt mode Jun 01 22:31:43 volumio3 kernel: [drm] Initialized v3d 1.0.0 20180419 for 1002000000.v3d on minor 0 Jun 01 22:31:43 volumio3 kernel: fuse: init (API version 7.39) Jun 01 22:31:43 volumio3 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Jun 01 22:31:43 volumio3 kernel: EXT4-fs (nvme0n1p2): recovery complete Jun 01 22:31:43 volumio3 kernel: EXT4-fs (nvme0n1p2): mounted filesystem e158ce43-90a0-4ed1-b254-0bcaf0c26091 r/w with ordered data mode. Quota mode: none. Jun 01 22:31:43 volumio3 kernel: loop0: detected capacity change from 0 to 1004312 Jun 01 22:31:43 volumio3 kernel: EXT4-fs (nvme0n1p3): recovery complete Jun 01 22:31:43 volumio3 kernel: EXT4-fs (nvme0n1p3): mounted filesystem 39856909-6eb0-448c-982b-aeb1888091d2 r/w with ordered data mode. Quota mode: none. Jun 01 22:31:43 volumio3 kernel: NET: Registered PF_INET6 protocol family Jun 01 22:31:43 volumio3 kernel: Segment Routing with IPv6 Jun 01 22:31:43 volumio3 kernel: In-situ OAM (IOAM) with IPv6 Jun 01 22:31:43 volumio3 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) Jun 01 22:31:43 volumio3 systemd[1]: Detected architecture arm64. Jun 01 22:31:43 volumio3 systemd[1]: Set hostname to . Jun 01 22:31:43 volumio3 kernel: uart-pl011 107d001000.serial: no DMA platform data Jun 01 22:31:43 volumio3 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. Jun 01 22:31:43 volumio3 systemd[1]: Reached target System Time Synchronized. Jun 01 22:31:43 volumio3 systemd[1]: Listening on fsck to fsckd communication Socket. Jun 01 22:31:43 volumio3 systemd[1]: Listening on Journal Socket. Jun 01 22:31:43 volumio3 systemd[1]: Mounting RPC Pipe File System... Jun 01 22:31:43 volumio3 systemd[1]: Starting Load Kernel Modules... Jun 01 22:31:43 volumio3 systemd[1]: Created slice system-systemd\x2dfsck.slice. Jun 01 22:31:43 volumio3 kernel: i2c_dev: i2c /dev entries driver Jun 01 22:31:43 volumio3 systemd-journald[411]: Journal started Jun 01 22:31:43 volumio3 systemd-journald[411]: Runtime journal (/run/log/journal/d59f8fba44ffb4c0d2e89736682361ca) is 3.7M, max 30.0M, 26.2M free. Jun 01 22:31:43 volumio3 systemd-modules-load[398]: Inserted module 'i2c_dev' Jun 01 22:31:43 volumio3 fake-hwclock[401]: Current system time: 2025-06-01 20:31:43 Jun 01 22:31:43 volumio3 fake-hwclock[401]: fake-hwclock saved clock information is in the past: 2025-06-01 20:31:19 Jun 01 22:31:43 volumio3 fake-hwclock[401]: To set system time to this saved clock anyway, use "force" Jun 01 22:31:43 volumio3 systemd[1]: Started Restore / save the current clock. Jun 01 22:31:43 volumio3 systemd[1]: Started Load/Save Random Seed. Jun 01 22:31:43 volumio3 systemd[1]: dynamicswap.service: Succeeded. Jun 01 22:31:43 volumio3 systemd[1]: Started Create System Users. Jun 01 22:31:43 volumio3 systemd[1]: Starting Create Static Device Nodes in /dev... Jun 01 22:31:43 volumio3 systemd[1]: Started udev Coldplug all Devices. Jun 01 22:31:43 volumio3 systemd[1]: Starting Helper to synchronize boot up for ifupdown... Jun 01 22:31:43 volumio3 systemd[1]: Started Create Static Device Nodes in /dev. Jun 01 22:31:43 volumio3 systemd[1]: Reached target Local File Systems (Pre). Jun 01 22:31:43 volumio3 systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Jun 01 22:31:43 volumio3 systemd[1]: Mounting /var/log... Jun 01 22:31:43 volumio3 systemd[1]: Mounting /var/spool/cups... Jun 01 22:31:43 volumio3 systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Jun 01 22:31:43 volumio3 systemd[1]: Mounting /tmp... Jun 01 22:31:43 volumio3 systemd[1]: Starting udev Kernel Device Manager... Jun 01 22:31:43 volumio3 systemd[1]: Mounted /var/log. Jun 01 22:31:43 volumio3 systemd[1]: Mounted /var/spool/cups. Jun 01 22:31:43 volumio3 systemd[1]: Mounted /tmp. Jun 01 22:31:43 volumio3 systemd[1]: Mounting /var/spool/cups/tmp... Jun 01 22:31:43 volumio3 systemd[1]: Starting Flush Journal to Persistent Storage... Jun 01 22:31:43 volumio3 systemd[1]: Mounted /var/spool/cups/tmp. Jun 01 22:31:43 volumio3 systemd-udevd[438]: Network interface NamePolicy= disabled on kernel command line, ignoring. Jun 01 22:31:43 volumio3 systemd-journald[411]: Runtime journal (/run/log/journal/d59f8fba44ffb4c0d2e89736682361ca) is 3.7M, max 30.0M, 26.2M free. Jun 01 22:31:43 volumio3 systemd[1]: Started Flush Journal to Persistent Storage. Jun 01 22:31:43 volumio3 systemd[1]: Started udev Kernel Device Manager. Jun 01 22:31:43 volumio3 systemd[1]: Starting Show Plymouth Boot Screen... Jun 01 22:31:43 volumio3 systemd[1]: plymouth-start.service: Succeeded. Jun 01 22:31:43 volumio3 systemd[1]: Started Show Plymouth Boot Screen. Jun 01 22:31:43 volumio3 systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Jun 01 22:31:43 volumio3 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jun 01 22:31:43 volumio3 systemd[1]: Reached target Local Encrypted Volumes. Jun 01 22:31:43 volumio3 systemd[1]: Reached target Paths. Jun 01 22:31:43 volumio3 kernel: mc: Linux media interface: v0.10 Jun 01 22:31:43 volumio3 kernel: rpi-gpiomem 107d508500.gpiomem: window base 0x107d508500 size 0x00000040 Jun 01 22:31:43 volumio3 kernel: rpi-gpiomem 107d508500.gpiomem: initialised 1 regions as /dev/gpiomem1 Jun 01 22:31:43 volumio3 kernel: rpi-gpiomem 107d517c00.gpiomem: window base 0x107d517c00 size 0x00000040 Jun 01 22:31:43 volumio3 kernel: rpi-gpiomem 107d517c00.gpiomem: initialised 1 regions as /dev/gpiomem2 Jun 01 22:31:43 volumio3 kernel: rp1_pio: Unknown symbol rp1_firmware_message (err -2) Jun 01 22:31:43 volumio3 kernel: rp1_pio: Unknown symbol devm_rp1_firmware_get (err -2) Jun 01 22:31:43 volumio3 kernel: rp1_pio: Unknown symbol rp1_firmware_get_feature (err -2) Jun 01 22:31:43 volumio3 kernel: rpi-gpiomem 107d504100.gpiomem: window base 0x107d504100 size 0x00000020 Jun 01 22:31:43 volumio3 kernel: rpi-gpiomem 107d504100.gpiomem: initialised 1 regions as /dev/gpiomem3 Jun 01 22:31:43 volumio3 kernel: rpi-gpiomem 107d510700.gpiomem: window base 0x107d510700 size 0x00000020 Jun 01 22:31:43 volumio3 kernel: rpi-gpiomem 107d510700.gpiomem: initialised 1 regions as /dev/gpiomem4 Jun 01 22:31:43 volumio3 systemd-udevd[450]: Using default interface naming scheme 'v240'. Jun 01 22:31:43 volumio3 systemd-udevd[450]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jun 01 22:31:43 volumio3 systemd[1]: Found device /dev/ttyAMA10. Jun 01 22:31:43 volumio3 kernel: videodev: Linux video capture interface: v2.00 Jun 01 22:31:43 volumio3 kernel: rpi-gpiomem 1f000d0000.gpiomem: window base 0x1f000d0000 size 0x00030000 Jun 01 22:31:43 volumio3 kernel: rpi-gpiomem 1f000d0000.gpiomem: initialised 1 regions as /dev/gpiomem0 Jun 01 22:31:43 volumio3 kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Jun 01 22:31:43 volumio3 kernel: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Jun 01 22:31:43 volumio3 kernel: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Jun 01 22:31:43 volumio3 kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Jun 01 22:31:43 volumio3 kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Jun 01 22:31:43 volumio3 kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. Jun 01 22:31:43 volumio3 kernel: rpivid 1000800000.codec: bcm2712_iommu_of_xlate: MMU 1000005100.iommu Jun 01 22:31:43 volumio3 kernel: pispbe 1000880000.pisp_be: bcm2712_iommu_of_xlate: MMU 1000005100.iommu Jun 01 22:31:43 volumio3 kernel: rpivid 1000800000.codec: Device registered as /dev/video19 Jun 01 22:31:43 volumio3 kernel: pispbe 1000880000.pisp_be: Runtime PM usage count underflow! Jun 01 22:31:43 volumio3 systemd[1]: Found device CT500P3SSD8 boot. Jun 01 22:31:43 volumio3 systemd[1]: Found device /sys/subsystem/net/devices/eth0. Jun 01 22:31:43 volumio3 kernel: input: ILITEK ILITEK-TOUCH as /devices/platform/axi/1000120000.pcie/1f00200000.usb/xhci-hcd.0/usb1/1-1/1-1:1.0/0003:222A:0001.0002/input/input3 Jun 01 22:31:43 volumio3 kernel: hid-multitouch 0003:222A:0001.0002: input,hiddev96,hidraw0: USB HID v1.10 Device [ILITEK ILITEK-TOUCH] on usb-xhci-hcd.0-1/input0 Jun 01 22:31:43 volumio3 kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Jun 01 22:31:43 volumio3 kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Jun 01 22:31:43 volumio3 kernel: brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,5-model-b.bin failed with error -2 Jun 01 22:31:43 volumio3 systemd[1]: Starting File System Check on /dev/disk/by-uuid/1B7B-9109... Jun 01 22:31:43 volumio3 systemd-udevd[480]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jun 01 22:31:43 volumio3 systemd-udevd[445]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jun 01 22:31:43 volumio3 kernel: Bluetooth: Core ver 2.22 Jun 01 22:31:43 volumio3 kernel: NET: Registered PF_BLUETOOTH protocol family Jun 01 22:31:43 volumio3 kernel: Bluetooth: HCI device and connection manager initialized Jun 01 22:31:43 volumio3 kernel: Bluetooth: HCI socket layer initialized Jun 01 22:31:43 volumio3 kernel: Bluetooth: L2CAP socket layer initialized Jun 01 22:31:43 volumio3 kernel: Bluetooth: SCO socket layer initialized Jun 01 22:31:43 volumio3 kernel: Bluetooth: HCI UART driver ver 2.3 Jun 01 22:31:43 volumio3 kernel: Bluetooth: HCI UART protocol H4 registered Jun 01 22:31:43 volumio3 kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Jun 01 22:31:43 volumio3 kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Jun 01 22:31:43 volumio3 kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Jun 01 22:31:43 volumio3 kernel: Bluetooth: HCI UART protocol Broadcom registered Jun 01 22:31:43 volumio3 kernel: usbcore: registered new interface driver brcmfmac Jun 01 22:31:43 volumio3 systemd[1]: Started File System Check Daemon to report status. Jun 01 22:31:43 volumio3 systemd-fsck[584]: fsck.fat 4.1 (2017-01-24) Jun 01 22:31:43 volumio3 systemd-fsck[584]: /dev/nvme0n1p1: 396 files, 166311/184582 clusters Jun 01 22:31:43 volumio3 systemd[1]: Started File System Check on /dev/disk/by-uuid/1B7B-9109. Jun 01 22:31:43 volumio3 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Jun 01 22:31:43 volumio3 systemd[1]: Mounting /boot... Jun 01 22:31:43 volumio3 systemd[1]: Mounted /boot. Jun 01 22:31:43 volumio3 systemd[1]: Reached target Local File Systems. Jun 01 22:31:43 volumio3 systemd[1]: Starting Preprocess NFS configuration... Jun 01 22:31:43 volumio3 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Jun 01 22:31:43 volumio3 sh[679]: command failed: No such device (-19) Jun 01 22:31:43 volumio3 systemd[1]: Starting Create Volatile Files and Directories... Jun 01 22:31:43 volumio3 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Jun 01 22:31:43 volumio3 systemd[1]: Started ifup for eth0. Jun 01 22:31:43 volumio3 thd[704]: Unable to parse trigger line: Jun 01 22:31:43 volumio3 thd[704]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Jun 01 22:31:43 volumio3 thd[704]: Unable to parse trigger line: Jun 01 22:31:43 volumio3 thd[704]: Found socket passed from systemd Jun 01 22:31:43 volumio3 systemd[1]: nfs-config.service: Succeeded. Jun 01 22:31:43 volumio3 mpd_monitor.sh[706]: MPD Monitor Service: Starting MPD Monitor Service Jun 01 22:31:43 volumio3 systemd[1]: Started Preprocess NFS configuration. Jun 01 22:31:43 volumio3 mpd_monitor.sh[706]: MPD error: Connection refused Jun 01 22:31:43 volumio3 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Jun 01 22:31:43 volumio3 volumio-time-update[707]: volumio-time-update-util: Fetching time from Volumio... Jun 01 22:31:43 volumio3 mpd_monitor.sh[706]: MPD Monitor Service: MPD Appears to be inactive, restarting Jun 01 22:31:43 volumio3 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Jun 01 22:31:43 volumio3 mpd_monitor.sh[706]: mpd: no process found Jun 01 22:31:43 volumio3 systemd[1]: Reached target NFS client services. Jun 01 22:31:43 volumio3 systemd[1]: Received SIGRTMIN+20 from PID 287 (plymouthd). Jun 01 22:31:43 volumio3 systemd[1]: plymouth-read-write.service: Succeeded. Jun 01 22:31:43 volumio3 systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Jun 01 22:31:43 volumio3 systemd[1]: Started Create Volatile Files and Directories. Jun 01 22:31:43 volumio3 systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Jun 01 22:31:43 volumio3 systemd[1]: Starting RPC bind portmap service... Jun 01 22:31:43 volumio3 dhcpcd[723]: Not running dhcpcd because /etc/network/interfaces Jun 01 22:31:43 volumio3 dhcpcd[723]: defines some interfaces that will use a Jun 01 22:31:43 volumio3 dhcpcd[723]: DHCP client or static address Jun 01 22:31:43 volumio3 systemd[1]: Starting Update UTMP about System Boot/Shutdown... Jun 01 22:31:43 volumio3 systemd[1]: Started Update UTMP about System Boot/Shutdown. Jun 01 22:31:43 volumio3 systemd[1]: Reached target System Initialization. Jun 01 22:31:43 volumio3 systemd[1]: Listening on triggerhappy.socket. Jun 01 22:31:43 volumio3 systemd[1]: Started Daily apt download activities. Jun 01 22:31:43 volumio3 systemd[1]: Started Daily apt upgrade and clean activities. Jun 01 22:31:43 volumio3 systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Jun 01 22:31:43 volumio3 systemd[1]: Started Daily man-db regeneration. Jun 01 22:31:43 volumio3 systemd[1]: Started Daily Cleanup of Temporary Directories. Jun 01 22:31:43 volumio3 systemd[1]: Reached target Timers. Jun 01 22:31:43 volumio3 systemd[1]: Listening on D-Bus System Message Bus Socket. Jun 01 22:31:43 volumio3 systemd[1]: Reached target Sockets. Jun 01 22:31:43 volumio3 systemd[1]: Reached target Basic System. Jun 01 22:31:43 volumio3 systemd[1]: Starting triggerhappy global hotkey daemon... Jun 01 22:31:43 volumio3 systemd[1]: Condition check resulted in Configure Bluetooth Modems connected by UART being skipped. Jun 01 22:31:43 volumio3 systemd[1]: Started UPnP Renderer front-end to MPD. Jun 01 22:31:43 volumio3 systemd[1]: Started MPD Monitor Service. Jun 01 22:31:43 volumio3 systemd[1]: Starting Volumio Time Update Utility... Jun 01 22:31:43 volumio3 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Jun 01 22:31:43 volumio3 systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Jun 01 22:31:43 volumio3 systemd[1]: Started Volumio Iptables Module. Jun 01 22:31:43 volumio3 systemd[1]: Started volumio-remote-updater.service. Jun 01 22:31:43 volumio3 systemd[1]: Started Volumio Log Rotation Service. Jun 01 22:31:43 volumio3 systemd[1]: Started D-Bus System Message Bus. Jun 01 22:31:43 volumio3 systemd[1]: Starting Login Service... Jun 01 22:31:43 volumio3 systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Jun 01 22:31:43 volumio3 systemd[1]: Starting Wireless Services... Jun 01 22:31:43 volumio3 systemd[1]: Starting WPA supplicant... Jun 01 22:31:43 volumio3 systemd[1]: Starting dhcpcd on all interfaces... Jun 01 22:31:43 volumio3 systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Jun 01 22:31:43 volumio3 systemd-logind[718]: New seat seat0. Jun 01 22:31:43 volumio3 systemd-logind[718]: Watching system buttons on /dev/input/event1 (pwr_button) Jun 01 22:31:43 volumio3 systemd-udevd[486]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jun 01 22:31:43 volumio3 kernel: brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob available (err=-2) Jun 01 22:31:43 volumio3 kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 Jun 01 22:31:43 volumio3 avahi-daemon[720]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Jun 01 22:31:43 volumio3 avahi-daemon[720]: Successfully dropped root privileges. Jun 01 22:31:43 volumio3 avahi-daemon[720]: avahi-daemon 0.7 starting up. Jun 01 22:31:43 volumio3 kernel: 8021q: 802.1Q VLAN Support v1.8 Jun 01 22:31:43 volumio3 systemd-udevd[486]: Using default interface naming scheme 'v240'. Jun 01 22:31:43 volumio3 systemd-udevd[486]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jun 01 22:31:43 volumio3 systemd-udevd[466]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jun 01 22:31:44 volumio3 kernel: vc4-drm axi:gpu: bcm2712_iommu_of_xlate: MMU 1000005200.iommu Jun 01 22:31:44 volumio3 kernel: usb 3-1: 1:3 : unsupported format bits 0x100000000 Jun 01 22:31:44 volumio3 kernel: Console: switching to colour dummy device 80x25 Jun 01 22:31:44 volumio3 kernel: vc4-drm axi:gpu: bound 107c580000.hvs (ops vc4_hvs_ops [vc4]) Jun 01 22:31:44 volumio3 kernel: Registered IR keymap rc-cec Jun 01 22:31:44 volumio3 kernel: rc rc0: vc4-hdmi-0 as /devices/platform/soc/107c701400.hdmi/rc/rc0 Jun 01 22:31:44 volumio3 kernel: input: vc4-hdmi-0 as /devices/platform/soc/107c701400.hdmi/rc/rc0/input5 Jun 01 22:31:44 volumio3 kernel: Bluetooth: hci0: BCM: chip id 107 Jun 01 22:31:44 volumio3 kernel: usbcore: registered new interface driver snd-usb-audio Jun 01 22:31:44 volumio3 kernel: input: vc4-hdmi-0 HDMI Jack as /devices/platform/soc/107c701400.hdmi/sound/card0/input6 Jun 01 22:31:44 volumio3 kernel: vc4-drm axi:gpu: bound 107c701400.hdmi (ops vc4_hdmi_ops [vc4]) Jun 01 22:31:44 volumio3 kernel: Bluetooth: hci0: BCM: features 0x2f Jun 01 22:31:44 volumio3 kernel: Bluetooth: hci0: BCM4345C0 Jun 01 22:31:44 volumio3 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Jun 01 22:31:44 volumio3 kernel: Registered IR keymap rc-cec Jun 01 22:31:44 volumio3 kernel: rc rc1: vc4-hdmi-1 as /devices/platform/soc/107c706400.hdmi/rc/rc1 Jun 01 22:31:44 volumio3 kernel: input: vc4-hdmi-1 as /devices/platform/soc/107c706400.hdmi/rc/rc1/input7 Jun 01 22:31:44 volumio3 kernel: input: vc4-hdmi-1 HDMI Jack as /devices/platform/soc/107c706400.hdmi/sound/card1/input8 Jun 01 22:31:44 volumio3 kernel: vc4-drm axi:gpu: bound 107c706400.hdmi (ops vc4_hdmi_ops [vc4]) Jun 01 22:31:44 volumio3 kernel: vc4-drm axi:gpu: bound 107c500000.mop (ops vc4_txp_ops [vc4]) Jun 01 22:31:44 volumio3 kernel: vc4-drm axi:gpu: bound 107c501000.moplet (ops vc4_txp_ops [vc4]) Jun 01 22:31:44 volumio3 kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Jun 01 22:31:44 volumio3 kernel: vc4-drm axi:gpu: bound 107c410000.pixelvalve (ops vc4_crtc_ops [vc4]) Jun 01 22:31:44 volumio3 kernel: vc4-drm axi:gpu: bound 107c411000.pixelvalve (ops vc4_crtc_ops [vc4]) Jun 01 22:31:44 volumio3 kernel: [drm] Initialized vc4 0.0.0 20140616 for axi:gpu on minor 1 Jun 01 22:31:44 volumio3 kernel: macb 1f00100000.ethernet eth0: PHY [1f00100000.ethernet-ffffffff:01] driver [Broadcom BCM54213PE] (irq=POLL) Jun 01 22:31:44 volumio3 kernel: macb 1f00100000.ethernet eth0: configuring for phy/rgmii-id link mode Jun 01 22:31:44 volumio3 kernel: pps pps0: new PPS source ptp0 Jun 01 22:31:44 volumio3 kernel: macb 1f00100000.ethernet: gem-ptp-timer ptp clock registered. Jun 01 22:31:44 volumio3 kernel: Console: switching to colour frame buffer device 160x50 Jun 01 22:31:44 volumio3 kernel: vc4-drm axi:gpu: [drm] fb0: vc4drmfb frame buffer device Jun 01 22:31:44 volumio3 sh[679]: eth0: waiting for carrier Jun 01 22:31:44 volumio3 volumio-time-update[707]: volumio-time-update-util: Date not found in response Jun 01 22:31:44 volumio3 volumio-time-update[707]: volumio-time-update-util: Retrying in 5 seconds... Jun 01 22:31:44 volumio3 volumio[705]: Could not open config: /tmp/upmpdcli.conf Jun 01 22:31:44 volumio3 avahi-daemon[720]: Successfully called chroot(). Jun 01 22:31:44 volumio3 volumio-remote-updater[709]: Error: No active session Jun 01 22:31:44 volumio3 volumio-remote-updater[709]: [2025-06-01 22:31:44] [info] asio async_connect error: system:111 (Connection refused) Jun 01 22:31:44 volumio3 volumio-remote-updater[709]: [2025-06-01 22:31:44] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 01 22:31:44 volumio3 volumio-remote-updater[709]: [2025-06-01 22:31:44] [error] handle_connect error: Underlying Transport Error Jun 01 22:31:44 volumio3 systemd[1]: Started Login Service. Jun 01 22:31:44 volumio3 avahi-daemon[720]: Successfully dropped remaining capabilities. Jun 01 22:31:44 volumio3 systemd[1]: Started RPC bind portmap service. Jun 01 22:31:44 volumio3 wpa_supplicant[722]: Successfully initialized wpa_supplicant Jun 01 22:31:44 volumio3 systemd[1]: Started triggerhappy global hotkey daemon. Jun 01 22:31:44 volumio3 avahi-daemon[720]: Loading service file /services/volumio.service. Jun 01 22:31:44 volumio3 systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Jun 01 22:31:44 volumio3 avahi-daemon[720]: Network interface enumeration completed. Jun 01 22:31:44 volumio3 systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Jun 01 22:31:44 volumio3 avahi-daemon[720]: Server startup complete. Host name is volumio3.local. Local service cookie is 146170304. Jun 01 22:31:44 volumio3 systemd[1]: Failed to start dhcpcd on all interfaces. Jun 01 22:31:44 volumio3 avahi-daemon[720]: Service "Volumio3" (/services/volumio.service) successfully established. Jun 01 22:31:44 volumio3 systemd-udevd[477]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jun 01 22:31:44 volumio3 dhcpcd[703]: eth0: waiting for carrier Jun 01 22:31:44 volumio3 systemd-logind[718]: Watching system buttons on /dev/input/event2 (vc4-hdmi-0) Jun 01 22:31:44 volumio3 systemd-udevd[448]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jun 01 22:31:44 volumio3 systemd-udevd[473]: Process '/bin/bash -c '/usr/local/bin/volumio usbattach'' failed with exit code 7. Jun 01 22:31:44 volumio3 systemd-udevd[466]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jun 01 22:31:44 volumio3 systemd-udevd[450]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jun 01 22:31:44 volumio3 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jun 01 22:31:44 volumio3 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jun 01 22:31:44 volumio3 systemd-logind[718]: Watching system buttons on /dev/input/event4 (vc4-hdmi-1) Jun 01 22:31:44 volumio3 systemd[1]: iptables.service: Succeeded. Jun 01 22:31:44 volumio3 haveged[693]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Jun 01 22:31:44 volumio3 haveged[693]: haveged: cpu: (VC); data: 64K (V); inst: 64K (V); idx: 39/40; sz: 63488/63488 Jun 01 22:31:44 volumio3 haveged[693]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99955 Jun 01 22:31:44 volumio3 haveged[693]: haveged: fills: 0, generated: 0 Jun 01 22:31:44 volumio3 systemd[1]: Started Avahi mDNS/DNS-SD Stack. Jun 01 22:31:44 volumio3 systemd[1]: Started WPA supplicant. Jun 01 22:31:44 volumio3 kernel: alsactl[798]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set Jun 01 22:31:44 volumio3 kernel: alsactl[797]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set Jun 01 22:31:44 volumio3 systemd[1]: Listening on mpd.socket. Jun 01 22:31:44 volumio3 systemd[1]: Started Manage Sound Card State (restore and store). Jun 01 22:31:44 volumio3 systemd[1]: Starting Save/Restore Sound Card State... Jun 01 22:31:44 volumio3 systemd[1]: Condition check resulted in Configure Bluetooth Modems connected by UART being skipped. Jun 01 22:31:44 volumio3 systemd[1]: Created slice system-bthelper.slice. Jun 01 22:31:44 volumio3 alsactl[822]: alsactl 1.1.8 daemon started Jun 01 22:31:44 volumio3 systemd[1]: Starting Raspberry Pi bluetooth helper... Jun 01 22:31:44 volumio3 systemd[1]: Starting Load/Save RF Kill Switch Status... Jun 01 22:31:44 volumio3 systemd[1]: Reached target RPC Port Mapper. Jun 01 22:31:44 volumio3 systemd[1]: Reached target Remote File Systems (Pre). Jun 01 22:31:44 volumio3 systemd[1]: Reached target Remote File Systems. Jun 01 22:31:44 volumio3 systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Jun 01 22:31:44 volumio3 systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Jun 01 22:31:44 volumio3 systemd[1]: Started Load/Save RF Kill Switch Status. Jun 01 22:31:44 volumio3 systemd[1]: Started Save/Restore Sound Card State. Jun 01 22:31:44 volumio3 systemd[1]: Reached target Sound Card. Jun 01 22:31:44 volumio3 systemd[1]: Started ifup for wlan0. Jun 01 22:31:44 volumio3 kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211 Jun 01 22:31:44 volumio3 loadcpufreq[828]: Loading cpufreq kernel modules...done (none). Jun 01 22:31:44 volumio3 systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Jun 01 22:31:44 volumio3 systemd[1]: Starting LSB: set CPUFreq kernel parameters... Jun 01 22:31:44 volumio3 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 01 22:31:44 volumio3 sh[832]: wlan0=wlan0 Jun 01 22:31:44 volumio3 cpufrequtils[876]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Jun 01 22:31:44 volumio3 systemd[1]: Started LSB: set CPUFreq kernel parameters. Jun 01 22:31:44 volumio3 wireless.js[721]: Cleaning previous... Jun 01 22:31:44 volumio3 sudo[918]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 01 22:31:44 volumio3 sudo[918]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:44 volumio3 sudo[918]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:44 volumio3 sudo[920]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jun 01 22:31:44 volumio3 sudo[920]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:44 volumio3 kernel: Bluetooth: hci0: BCM: features 0x2f Jun 01 22:31:44 volumio3 kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Jun 01 22:31:44 volumio3 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Jun 01 22:31:44 volumio3 kernel: Bluetooth: hci0: BCM: Using default device address (43:45:c0:00:1f:ac) Jun 01 22:31:44 volumio3 bthelper[826]: Raspberry Pi BDADDR already set Jun 01 22:31:44 volumio3 systemd[1]: Started Raspberry Pi bluetooth helper. Jun 01 22:31:44 volumio3 systemd[1]: Starting Bluetooth service... Jun 01 22:31:44 volumio3 bluetoothd[930]: Bluetooth daemon 5.50 Jun 01 22:31:44 volumio3 bluetoothd[930]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Jun 01 22:31:44 volumio3 systemd[1]: Started Bluetooth service. Jun 01 22:31:44 volumio3 systemd[1]: Reached target Bluetooth. Jun 01 22:31:44 volumio3 bluetoothd[930]: Starting SDP server Jun 01 22:31:44 volumio3 bluetoothd[930]: Excluding (cli) sap Jun 01 22:31:44 volumio3 bluetoothd[930]: Bluetooth management interface 1.22 initialized Jun 01 22:31:44 volumio3 dbus-daemon[711]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 pid=930 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Jun 01 22:31:44 volumio3 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Jun 01 22:31:44 volumio3 kernel: Bluetooth: BNEP filters: protocol multicast Jun 01 22:31:44 volumio3 kernel: Bluetooth: BNEP socket layer initialized Jun 01 22:31:44 volumio3 kernel: Bluetooth: MGMT ver 1.22 Jun 01 22:31:44 volumio3 systemd[1]: Starting Hostname Service... Jun 01 22:31:44 volumio3 bluetoothd[930]: Failed to set privacy: Rejected (0x0b) Jun 01 22:31:45 volumio3 sudo[920]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:45 volumio3 wireless.js[721]: Stopped aP Jun 01 22:31:45 volumio3 wireless.js[721]: Wireless Networking DISABLED, not starting wireless flow Jun 01 22:31:45 volumio3 dbus-daemon[711]: [system] Successfully activated service 'org.freedesktop.hostname1' Jun 01 22:31:45 volumio3 systemd[1]: Started Hostname Service. Jun 01 22:31:45 volumio3 systemd[1]: wireless.service: Succeeded. Jun 01 22:31:45 volumio3 systemd[1]: Started Wireless Services. Jun 01 22:31:45 volumio3 systemd[1]: Started Volumio Backend Module. Jun 01 22:31:45 volumio3 systemd[1]: Started Volumio Cpu Tweaker. Jun 01 22:31:45 volumio3 volumio-cpu-tweak[940]: Setting RT Priority for mpd Jun 01 22:31:45 volumio3 volumio-cpu-tweak[940]: pid 35's current scheduling policy: SCHED_OTHER Jun 01 22:31:45 volumio3 volumio-cpu-tweak[940]: pid 35's current scheduling priority: 0 Jun 01 22:31:45 volumio3 volumio-cpu-tweak[940]: Setting MPD Affinity Jun 01 22:31:45 volumio3 volumio-cpu-tweak[940]: pid 3's current affinity mask: f Jun 01 22:31:45 volumio3 volumio-cpu-tweak[940]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jun 01 22:31:45 volumio3 volumio-cpu-tweak[940]: VOLUMIO CPU TWEAK: Setting CPU Governor: conservative Jun 01 22:31:45 volumio3 systemd[1]: Started Helper to synchronize boot up for ifupdown. Jun 01 22:31:45 volumio3 systemd[1]: Starting Raise network interfaces... Jun 01 22:31:45 volumio3 systemd[1]: volumio_cpu_tweak.service: Succeeded. Jun 01 22:31:45 volumio3 systemd[1]: Started Raise network interfaces. Jun 01 22:31:45 volumio3 systemd[1]: Reached target Network. Jun 01 22:31:45 volumio3 systemd[1]: Starting OpenBSD Secure Shell server... Jun 01 22:31:45 volumio3 systemd[1]: Starting Music Player Daemon... Jun 01 22:31:45 volumio3 systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Jun 01 22:31:45 volumio3 systemd[1]: Starting Permit User Sessions... Jun 01 22:31:45 volumio3 systemd[1]: Starting Network Time Service... Jun 01 22:31:45 volumio3 systemd[1]: Reached target Network is Online. Jun 01 22:31:45 volumio3 systemd[1]: Starting LSB: Brings up/down network automatically... Jun 01 22:31:45 volumio3 systemd[1]: Starting /etc/rc.local Compatibility... Jun 01 22:31:45 volumio3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 01 22:31:45 volumio3 systemd[1]: Starting Samba NMB Daemon... Jun 01 22:31:45 volumio3 sudo[1013]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 01 22:31:45 volumio3 systemd[1]: Started Permit User Sessions. Jun 01 22:31:45 volumio3 sudo[1013]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:45 volumio3 systemd[1]: Started /etc/rc.local Compatibility. Jun 01 22:31:45 volumio3 sudo[1013]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jun 01 22:31:45 volumio3 sudo[1013]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:45 volumio3 systemd[1]: Starting Hold until boot process finishes up... Jun 01 22:31:45 volumio3 systemd[1]: Starting Terminate Plymouth Boot Screen... Jun 01 22:31:45 volumio3 systemd[1]: Received SIGRTMIN+21 from PID 287 (plymouthd). Jun 01 22:31:45 volumio3 sshd[1032]: Server listening on 0.0.0.0 port 22. Jun 01 22:31:45 volumio3 sshd[1032]: Server listening on :: port 22. Jun 01 22:31:45 volumio3 systemd[1]: Started OpenBSD Secure Shell server. Jun 01 22:31:45 volumio3 ntpd[1015]: ntpd 4.2.8p12@1.3728-o (1): Starting Jun 01 22:31:45 volumio3 ntpd[1015]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Jun 01 22:31:45 volumio3 ntpd[1039]: proto: precision = 0.352 usec (-21) Jun 01 22:31:45 volumio3 systemd[1]: Started Network Time Service. Jun 01 22:31:45 volumio3 ntpd[1039]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jun 01 22:31:45 volumio3 ntpd[1039]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jun 01 22:31:45 volumio3 ntpd[1039]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 156 days ago Jun 01 22:31:45 volumio3 ntpd[1039]: Listen and drop on 0 v6wildcard [::]:123 Jun 01 22:31:45 volumio3 ntpd[1039]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jun 01 22:31:45 volumio3 ntpd[1039]: Listen normally on 2 lo 127.0.0.1:123 Jun 01 22:31:45 volumio3 ntpd[1039]: Listening on routing socket on fd #19 for interface updates Jun 01 22:31:45 volumio3 ntpd[1039]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 01 22:31:45 volumio3 ntpd[1039]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 01 22:31:45 volumio3 systemd[1]: Received SIGRTMIN+21 from PID 287 (plymouthd). Jun 01 22:31:45 volumio3 ifplugd[1016]: Network Interface Plugging Daemon...error: unexpectedly disconnected from boot status daemon Jun 01 22:31:45 volumio3 systemd[1]: plymouth-quit-wait.service: Succeeded. Jun 01 22:31:45 volumio3 systemd[1]: Started Hold until boot process finishes up. Jun 01 22:31:45 volumio3 systemd[1]: plymouth-quit.service: Succeeded. Jun 01 22:31:45 volumio3 systemd[1]: Started Terminate Plymouth Boot Screen. Jun 01 22:31:45 volumio3 ifplugd(eth0)[1049]: ifplugd 0.28 initializing. Jun 01 22:31:45 volumio3 ifplugd(eth0)[1049]: Using interface eth0/2C:CF:67:8C:50:FB with driver (version: 6.6.62-v8+) Jun 01 22:31:45 volumio3 systemd[1]: Started Serial Getty on ttyAMA10. Jun 01 22:31:45 volumio3 ifplugd(eth0)[1049]: Using detection mode: SIOCETHTOOL Jun 01 22:31:45 volumio3 systemd[1]: Reached target Login Prompts. Jun 01 22:31:45 volumio3 ifplugd(eth0)[1049]: Initialization complete, link beat not detected. Jun 01 22:31:45 volumio3 ifplugd[1016]: start eth0...done. Jun 01 22:31:45 volumio3 systemd[1]: Started LSB: Brings up/down network automatically. Jun 01 22:31:45 volumio3 nmbd[1027]: [2025/06/01 22:31:45.627003, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Jun 01 22:31:45 volumio3 nmbd[1027]: started asyncdns process 1050 Jun 01 22:31:45 volumio3 nmbd[1027]: [2025/06/01 22:31:45.627587, 0] ../lib/util/become_daemon.c:149(daemon_status) Jun 01 22:31:45 volumio3 nmbd[1027]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Jun 01 22:31:45 volumio3 nmbd[1027]: [2025/06/01 22:31:45.627620, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Jun 01 22:31:45 volumio3 nmbd[1027]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jun 01 22:31:46 volumio3 mpd[1029]: Jun 01 22:31 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 01 22:31:46 volumio3 systemd[1]: Started Music Player Daemon. Jun 01 22:31:46 volumio3 mpd_monitor.sh[706]: MPD Monitor Service: MPD restarted due to no mpc output. Jun 01 22:31:46 volumio3 volumio[939]: info: ------------------------------------------- Jun 01 22:31:46 volumio3 volumio[939]: info: ----- Volumio3 ---- Jun 01 22:31:46 volumio3 volumio[939]: info: ------------------------------------------- Jun 01 22:31:46 volumio3 volumio[939]: info: ----- System startup ---- Jun 01 22:31:46 volumio3 volumio[939]: info: ------------------------------------------- Jun 01 22:31:46 volumio3 ntpd[1039]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jun 01 22:31:46 volumio3 volumio[939]: info: MYVOLUMIO Environment detected Jun 01 22:31:46 volumio3 volumio[939]: info: Plugin folders cleanup Jun 01 22:31:46 volumio3 volumio[939]: info: Scanning into folder /volumio/app/plugins/ Jun 01 22:31:46 volumio3 volumio[939]: info: Scanning category audio_interface Jun 01 22:31:46 volumio3 volumio[939]: info: Scanning category miscellanea Jun 01 22:31:46 volumio3 volumio[939]: info: Scanning category music_service Jun 01 22:31:46 volumio3 volumio[939]: info: Scanning category plugins.json Jun 01 22:31:46 volumio3 volumio[939]: info: Scanning category system_controller Jun 01 22:31:46 volumio3 volumio[939]: info: Scanning category user_interface Jun 01 22:31:46 volumio3 volumio[939]: info: Scanning into folder /data/plugins/ Jun 01 22:31:46 volumio3 volumio[939]: info: Scanning category music_service Jun 01 22:31:46 volumio3 volumio[939]: info: Scanning category user_interface Jun 01 22:31:46 volumio3 volumio[939]: info: Plugin folders cleanup completed Jun 01 22:31:46 volumio3 volumio[939]: info: ------------------------------------------- Jun 01 22:31:46 volumio3 volumio[939]: info: ----- Core plugins startup ---- Jun 01 22:31:46 volumio3 volumio[939]: info: ------------------------------------------- Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugins from folder /volumio/app/plugins/ Jun 01 22:31:46 volumio3 volumio[939]: info: Adding plugin upnp to MyMusic Plugins Jun 01 22:31:46 volumio3 volumio[939]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 01 22:31:46 volumio3 volumio[939]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugins from folder /data/plugins/ Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "system"... Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "appearance"... Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "network"... Jun 01 22:31:46 volumio3 volumio[939]: info: Refreshing Cached IP Addresses Jun 01 22:31:46 volumio3 sudo[1068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 01 22:31:46 volumio3 sudo[1068]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:46 volumio3 sudo[1068]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:46 volumio3 sudo[1070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "services"... Jun 01 22:31:46 volumio3 sudo[1070]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "alsa_controller"... Jun 01 22:31:46 volumio3 sudo[1070]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:46 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "wizard"... Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "networkfs"... Jun 01 22:31:46 volumio3 volumio[939]: info: Starting Udev Watcher for removable devices Jun 01 22:31:46 volumio3 sudo[1091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Joachim,password=Apfelmann2773,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,noserverino //192.168.178.1/FRITZ.NAS/USB1/Musik/Alben /mnt/NAS/My_Music Jun 01 22:31:46 volumio3 sudo[1091]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:46 volumio3 volumio[939]: info: Ignoring mount for partition: boot Jun 01 22:31:46 volumio3 volumio[939]: info: Ignoring mount for partition: volumio Jun 01 22:31:46 volumio3 volumio[939]: info: Ignoring mount for partition: volumio_data Jun 01 22:31:46 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "volumio_command_line_client"... Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "upnp"... Jun 01 22:31:46 volumio3 volumio[939]: info: [1748809906927] Starting Upmpd Daemon Jun 01 22:31:46 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "my_music"... Jun 01 22:31:46 volumio3 volumio[939]: info: Loading plugin "mpd"... Jun 01 22:31:46 volumio3 kernel: Key type cifs.spnego registered Jun 01 22:31:46 volumio3 kernel: Key type cifs.idmap registered Jun 01 22:31:46 volumio3 sudo[1091]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:46 volumio3 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. Jun 01 22:31:46 volumio3 kernel: CIFS: Attempting to mount //192.168.178.1/FRITZ.NAS/USB1/Musik/Alben Jun 01 22:31:46 volumio3 kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Jun 01 22:31:46 volumio3 kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "upnp_browser"... Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "alarm-clock"... Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "airplay_emulation"... Jun 01 22:31:47 volumio3 volumio[939]: info: Starting Shairport Sync Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "last_100"... Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "webradio"... Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "i2s_dacs"... Jun 01 22:31:47 volumio3 volumio[939]: info: I2S DAC not set, start Auto-detection Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "volumiodiscovery"... Jun 01 22:31:47 volumio3 volumio[939]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 01 22:31:47 volumio3 volumio[939]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 01 22:31:47 volumio3 volumio[939]: *** WARNING *** For more information see Jun 01 22:31:47 volumio3 volumio[939]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 01 22:31:47 volumio3 volumio[939]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 01 22:31:47 volumio3 volumio[939]: *** WARNING *** For more information see Jun 01 22:31:47 volumio3 node[939]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 01 22:31:47 volumio3 node[939]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 01 22:31:47 volumio3 node[939]: *** WARNING *** For more information see Jun 01 22:31:47 volumio3 node[939]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 01 22:31:47 volumio3 node[939]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 01 22:31:47 volumio3 node[939]: *** WARNING *** For more information see Jun 01 22:31:47 volumio3 volumio[939]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 01 22:31:47 volumio3 volumio[939]: info: Discovery: Started advertising with name: Volumio3 Jun 01 22:31:47 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "spop"... Jun 01 22:31:47 volumio3 ntpd[1039]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "outputs"... Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "albumart"... Jun 01 22:31:47 volumio3 volumio[939]: info: Plugin example_plugin is not enabled Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "inputs"... Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "updater_comm"... Jun 01 22:31:47 volumio3 volumio[939]: info: Plugin mpdemulation is not enabled Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "rest_api"... Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "websocket"... Jun 01 22:31:47 volumio3 volumio[939]: info: Starting Socket.io Server version 2.3.0 Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "Systeminfo"... Jun 01 22:31:47 volumio3 volumio[939]: Forking 3 albumart workers Jun 01 22:31:47 volumio3 volumio[939]: info: Loading plugin "touch_display"... Jun 01 22:31:47 volumio3 volumio[939]: Starting albumart workers Jun 01 22:31:47 volumio3 volumio[939]: Starting albumart workers Jun 01 22:31:47 volumio3 volumio[939]: Starting albumart workers Jun 01 22:31:47 volumio3 volumio[939]: info: Applying required configuration parameters for plugin touch_display Jun 01 22:31:47 volumio3 volumio[939]: info: Loading i18n strings for locale de Jun 01 22:31:47 volumio3 volumio[939]: Updating browse sources language Jun 01 22:31:47 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::initPlayerControls Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: Express server listening on port 3000 Jun 01 22:31:48 volumio3 volumio[939]: [Metrics] WebUI: 2s 78.83ms Jun 01 22:31:48 volumio3 volumio[939]: info: CoreStateMachine::resetVolumioState Jun 01 22:31:48 volumio3 volumio[939]: info: CoreStateMachine::getcurrentVolume Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::volumioRetrievevolume Jun 01 22:31:48 volumio3 volumio[939]: info: CoreStateMachine::pushState Jun 01 22:31:48 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::volumioPushState Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: Cannot read play queue from file Jun 01 22:31:48 volumio3 volumio[939]: info: Volumio Network Manager: Network status updated: 0 Jun 01 22:31:48 volumio3 volumio[939]: info: Cannot mount NAS My_Music at system boot, trial number 1 ,retrying in 5 seconds Jun 01 22:31:48 volumio3 volumio[939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 01 22:31:48 volumio3 volumio[939]: info: CoreStateMachine::setRepeat null single undefined Jun 01 22:31:48 volumio3 volumio[939]: info: CoreStateMachine::pushState Jun 01 22:31:48 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::volumioPushState Jun 01 22:31:48 volumio3 volumio[939]: info: CoreStateMachine::setRandom null Jun 01 22:31:48 volumio3 volumio[939]: info: CoreStateMachine::pushState Jun 01 22:31:48 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::volumioPushState Jun 01 22:31:48 volumio3 volumio[939]: info: Setting Device type: Raspberry PI Jun 01 22:31:48 volumio3 volumio[939]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jun 01 22:31:48 volumio3 volumio[939]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d04170 Jun 01 22:31:48 volumio3 volumio[939]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jun 01 22:31:48 volumio3 volumio[939]: info: Completed loading Core Plugins Jun 01 22:31:48 volumio3 volumio[939]: info: Preparing to generate the ALSA configuration file Jun 01 22:31:48 volumio3 volumio[939]: info: Asound.conf file unchanged, so no further update is needed Jun 01 22:31:48 volumio3 volumio[939]: info: Output device has changed, restarting MPD Jun 01 22:31:48 volumio3 sudo[1168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 01 22:31:48 volumio3 sudo[1168]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 volumio[939]: info: Output device has changed, restarting Shairport Sync Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 22:31:48 volumio3 sudo[1168]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 sudo[1171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 01 22:31:48 volumio3 sudo[1171]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 systemd[1]: Stopping Music Player Daemon... Jun 01 22:31:48 volumio3 volumio[939]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 01 22:31:48 volumio3 volumio[939]: info: ___________ START PLUGINS ___________ Jun 01 22:31:48 volumio3 volumio[939]: info: ControllerMpd::onStart: Initializing MPD Jun 01 22:31:48 volumio3 volumio[939]: info: Creating MPD Configuration file Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 22:31:48 volumio3 sudo[1177]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 01 22:31:48 volumio3 sudo[1177]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 01 22:31:48 volumio3 volumio[939]: info: [1748809908148] CoreMusicLibrary::Adding element Medienserver Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 01 22:31:48 volumio3 sudo[1177]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 sudo[1179]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 01 22:31:48 volumio3 sudo[1179]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 22:31:48 volumio3 systemd[1]: mpd.service: Succeeded. Jun 01 22:31:48 volumio3 systemd[1]: Stopped Music Player Daemon. Jun 01 22:31:48 volumio3 volumio[939]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 01 22:31:48 volumio3 volumio[939]: info: [1748809908181] CoreMusicLibrary::Adding element Last_100 Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 01 22:31:48 volumio3 volumio[939]: info: [1748809908181] CoreMusicLibrary::Adding element Webradio Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 01 22:31:48 volumio3 volumio[939]: info: Initializing BBC Radios Jun 01 22:31:48 volumio3 systemd[1]: Starting Music Player Daemon... Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: Creating Spotify config file Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 sudo[1188]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 01 22:31:48 volumio3 sudo[1188]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 sudo[1188]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 volumio[939]: info: Loading i18n strings for locale de Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 01 22:31:48 volumio3 volumio[939]: info: Volumio Calling Home Jun 01 22:31:48 volumio3 sudo[1205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Jun 01 22:31:48 volumio3 sudo[1205]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 sh[679]: eth0: carrier acquired Jun 01 22:31:48 volumio3 dhcpcd[703]: eth0: carrier acquired Jun 01 22:31:48 volumio3 kernel: macb 1f00100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off Jun 01 22:31:48 volumio3 sudo[1210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jun 01 22:31:48 volumio3 sudo[1210]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 sudo[1207]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Jun 01 22:31:48 volumio3 sh[679]: DUID 00:01:00:01:2f:b6:20:2e:2c:cf:67:8c:50:fb Jun 01 22:31:48 volumio3 sh[679]: eth0: IAID 67:8c:50:fb Jun 01 22:31:48 volumio3 sh[679]: eth0: adding address fe80::2ecf:67ff:fe8c:50fb Jun 01 22:31:48 volumio3 sh[679]: ipv6_addaddr1: Permission denied Jun 01 22:31:48 volumio3 dhcpcd[703]: DUID 00:01:00:01:2f:b6:20:2e:2c:cf:67:8c:50:fb Jun 01 22:31:48 volumio3 dhcpcd[703]: eth0: IAID 67:8c:50:fb Jun 01 22:31:48 volumio3 dhcpcd[703]: eth0: adding address fe80::2ecf:67ff:fe8c:50fb Jun 01 22:31:48 volumio3 dhcpcd[703]: ipv6_addaddr1: Permission denied Jun 01 22:31:48 volumio3 sudo[1207]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 volumio[939]: Unhandled rejection Error: No sockets available, cannot start. Jun 01 22:31:48 volumio3 volumio[939]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Jun 01 22:31:48 volumio3 volumio[939]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Jun 01 22:31:48 volumio3 volumio[939]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Jun 01 22:31:48 volumio3 volumio[939]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Jun 01 22:31:48 volumio3 volumio[939]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Jun 01 22:31:48 volumio3 volumio[939]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Jun 01 22:31:48 volumio3 volumio[939]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Jun 01 22:31:48 volumio3 volumio[939]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Jun 01 22:31:48 volumio3 volumio[939]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Jun 01 22:31:48 volumio3 volumio[939]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Jun 01 22:31:48 volumio3 volumio[939]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Jun 01 22:31:48 volumio3 volumio[939]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jun 01 22:31:48 volumio3 volumio[939]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jun 01 22:31:48 volumio3 volumio[939]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Jun 01 22:31:48 volumio3 volumio[939]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Jun 01 22:31:48 volumio3 volumio[939]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 01 22:31:48 volumio3 volumio[939]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: No backlight interface detected. Jun 01 22:31:48 volumio3 sudo[1205]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 volumio[939]: info: MPD Permissions set Jun 01 22:31:48 volumio3 systemd[1]: Reloading. Jun 01 22:31:48 volumio3 volumio[939]: info: Spotify config file written Jun 01 22:31:48 volumio3 volumio[939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 sudo[1215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 01 22:31:48 volumio3 sudo[1215]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 22:31:48 volumio3 volumio[939]: info: No need to fix Spotify hosts Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: systemctl stop getty@tty1.service succeeded. Jun 01 22:31:48 volumio3 ntpd[1039]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Jun 01 22:31:48 volumio3 sudo[1239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Jun 01 22:31:48 volumio3 sudo[1239]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 volumio[939]: info: Starting Shairport Sync Jun 01 22:31:48 volumio3 sudo[1242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Jun 01 22:31:48 volumio3 sudo[1239]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 volumio[939]: info: Starting Shairport Sync Jun 01 22:31:48 volumio3 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. Jun 01 22:31:48 volumio3 sudo[1244]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 01 22:31:48 volumio3 sudo[1244]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 sudo[1242]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 volumio[939]: info: Starting Shairport Sync Jun 01 22:31:48 volumio3 sudo[1248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 01 22:31:48 volumio3 sudo[1248]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:48 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:48 volumio3 sudo[1250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 01 22:31:48 volumio3 sudo[1250]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Jun 01 22:31:48 volumio3 systemd[1]: serial-getty@ttyAMA10.service: Current command vanished from the unit file, execution of the command list won't be resumed. Jun 01 22:31:48 volumio3 systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Jun 01 22:31:48 volumio3 mpd[1200]: Jun 01 22:31 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 01 22:31:48 volumio3 ifplugd(eth0)[1049]: Link beat detected. Jun 01 22:31:48 volumio3 systemd[1]: Started Music Player Daemon. Jun 01 22:31:48 volumio3 sudo[1171]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 sudo[1210]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 sudo[1179]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 volumio[939]: error: updateQueue error: null Jun 01 22:31:48 volumio3 systemd[1]: Reloading. Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: systemctl daemon-reload succeeded. Jun 01 22:31:48 volumio3 volumio[939]: error: updateQueue error: null Jun 01 22:31:48 volumio3 volumio[939]: info: MPD running with PID1200 Jun 01 22:31:48 volumio3 volumio[939]: ,establishing connection Jun 01 22:31:48 volumio3 sudo[1258]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Jun 01 22:31:48 volumio3 sudo[1258]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:48 volumio3 volumio[939]: error: updateQueue error: null Jun 01 22:31:48 volumio3 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. Jun 01 22:31:48 volumio3 ifplugd(eth0)[1049]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Jun 01 22:31:48 volumio3 ifplugd(eth0)[1049]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Jun 01 22:31:48 volumio3 sh[679]: eth0: soliciting a DHCP lease Jun 01 22:31:48 volumio3 dhcpcd[703]: eth0: soliciting a DHCP lease Jun 01 22:31:48 volumio3 sudo[1207]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: systemctl disable getty@tty1.service succeeded. Jun 01 22:31:48 volumio3 sh[679]: eth0: offered 192.168.178.32 from 192.168.178.1 Jun 01 22:31:48 volumio3 dhcpcd[703]: eth0: offered 192.168.178.32 from 192.168.178.1 Jun 01 22:31:48 volumio3 sh[679]: eth0: probing address 192.168.178.32/24 Jun 01 22:31:48 volumio3 dhcpcd[703]: eth0: probing address 192.168.178.32/24 Jun 01 22:31:48 volumio3 systemd[1]: Started Volumio Kiosk. Jun 01 22:31:48 volumio3 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 01 22:31:48 volumio3 sudo[1258]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 systemd[1]: Started go-librespot Daemon. Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: Volumio Kiosk started. Jun 01 22:31:48 volumio3 sudo[1215]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 go-librespot[1279]: go-librespot daemon starting... Jun 01 22:31:48 volumio3 systemd[1]: shairport-sync.service: Succeeded. Jun 01 22:31:48 volumio3 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 01 22:31:48 volumio3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:48 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:48 volumio3 sudo[1248]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 sudo[1250]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 volumio[939]: info: Completed starting Core Plugins Jun 01 22:31:48 volumio3 volumio[939]: info: ------------------------------------------- Jun 01 22:31:48 volumio3 volumio[939]: info: ----- MyVolumio plugins startup ---- Jun 01 22:31:48 volumio3 volumio[939]: info: ------------------------------------------- Jun 01 22:31:48 volumio3 volumio[939]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 01 22:31:48 volumio3 sudo[1244]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:48 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:48 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:48 volumio3 volumio[939]: info: Shairport-Sync Started Jun 01 22:31:48 volumio3 volumio[939]: Error adding Membership: Error: addMembership EINVAL Jun 01 22:31:48 volumio3 volumio[939]: info: Shairport-Sync Started Jun 01 22:31:48 volumio3 volumio[939]: info: Shairport-Sync Started Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: X display number found: Jun 01 22:31:48 volumio3 go-librespot[1279]: time="2025-06-01T22:31:48+02:00" level=info msg="running go-librespot 0.2.0" Jun 01 22:31:48 volumio3 go-librespot[1279]: time="2025-06-01T22:31:48+02:00" level=debug msg="app state loaded" Jun 01 22:31:48 volumio3 go-librespot[1279]: time="2025-06-01T22:31:48+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 22:31:48 volumio3 go-librespot[1279]: time="2025-06-01T22:31:48+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 01 22:31:48 volumio3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 22:31:48 volumio3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 22:31:48 volumio3 startx[1278]: X.Org X Server 1.20.4 Jun 01 22:31:48 volumio3 startx[1278]: X Protocol Version 11, Revision 0 Jun 01 22:31:48 volumio3 startx[1278]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Jun 01 22:31:48 volumio3 startx[1278]: Current Operating System: Linux volumio3 6.6.62-v8+ #1816 SMP PREEMPT Mon Nov 18 15:35:52 GMT 2024 aarch64 Jun 01 22:31:48 volumio3 startx[1278]: Kernel command line: reboot=w coherent_pool=1M 8250.nr_uarts=1 pci=pcie_bus_safe cgroup_disable=memory numa_policy=interleave numa=fake=8 system_heap.max_order=0 smsc95xx.macaddr=2C:CF:67:8C:50:FB vc_mem.mem_base=0x3fc00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyAMA10,115200 console=tty1 imgpart=UUID=e158ce43-90a0-4ed1-b254-0bcaf0c26091 imgfile=/volumio_current.sqsh bootpart=UUID=1B7B-9109 datapart=UUID=39856909-6eb0-448c-982b-aeb1888091d2 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Jun 01 22:31:48 volumio3 startx[1278]: Build Date: 04 April 2023 07:50:56AM Jun 01 22:31:48 volumio3 startx[1278]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Jun 01 22:31:48 volumio3 startx[1278]: Current version of pixman: 0.36.0 Jun 01 22:31:48 volumio3 startx[1278]: Before reporting problems, check http://wiki.x.org Jun 01 22:31:48 volumio3 startx[1278]: to make sure that you have the latest version. Jun 01 22:31:48 volumio3 startx[1278]: Markers: (--) probed, (**) from config file, (==) default setting, Jun 01 22:31:48 volumio3 startx[1278]: (++) from command line, (!!) notice, (II) informational, Jun 01 22:31:48 volumio3 startx[1278]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jun 01 22:31:48 volumio3 startx[1278]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun Jun 1 22:31:48 2025 Jun 01 22:31:48 volumio3 startx[1278]: (==) Using config directory: "/etc/X11/xorg.conf.d" Jun 01 22:31:48 volumio3 startx[1278]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jun 01 22:31:48 volumio3 volumio[939]: info: touch_display: X display number found: 0 Jun 01 22:31:49 volumio3 volumio[939]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jun 01 22:31:49 volumio3 volumio[939]: info: touch_display: X display number found: 0 Jun 01 22:31:49 volumio3 sh[679]: eth0: soliciting an IPv6 router Jun 01 22:31:49 volumio3 dhcpcd[703]: eth0: soliciting an IPv6 router Jun 01 22:31:49 volumio3 volumio-remote-updater[709]: [2025-06-01 22:31:49] [connect] Successful connection Jun 01 22:31:49 volumio3 volumio-remote-updater[709]: [2025-06-01 22:31:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1748809909 101 Jun 01 22:31:49 volumio3 volumio[939]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Jun 01 22:31:49 volumio3 volumio-time-update[707]: volumio-time-update-util: Fetching time from Volumio... Jun 01 22:31:49 volumio3 volumio-time-update[707]: volumio-time-update-util: Date not found in response Jun 01 22:31:49 volumio3 volumio-time-update[707]: volumio-time-update-util: Retrying in 5 seconds... Jun 01 22:31:49 volumio3 ntpd[1039]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jun 01 22:31:49 volumio3 systemd[1]: systemd-rfkill.service: Succeeded. Jun 01 22:31:49 volumio3 startx[1278]: V3D 7.1 not supported by this version of Mesa. Jun 01 22:31:49 volumio3 kernel: broken atomic modeset userspace detected, disabling atomic Jun 01 22:31:49 volumio3 startx[1278]: (II) modeset(0): Initializing kms color map for depth 24, 8 bpc. Jun 01 22:31:49 volumio3 bthelper[826]: Changing power off succeeded Jun 01 22:31:49 volumio3 bthelper[826]: [CHG] Controller 2C:CF:67:8C:50:FD Class: 0x0000041c Jun 01 22:31:49 volumio3 bthelper[826]: Changing power on succeeded Jun 01 22:31:50 volumio3 volumio[939]: info: touch_display: Setting screensaver timeout to 0 seconds. Jun 01 22:31:51 volumio3 volumio[939]: info: go-librespot daemon successfully initialized Jun 01 22:31:51 volumio3 volumio[939]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS aarch64 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Jun 01 22:31:52 volumio3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 22:31:52 volumio3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jun 01 22:31:52 volumio3 systemd[1]: Stopped go-librespot Daemon. Jun 01 22:31:52 volumio3 systemd[1]: Started go-librespot Daemon. Jun 01 22:31:52 volumio3 go-librespot[1522]: go-librespot daemon starting... Jun 01 22:31:52 volumio3 go-librespot[1522]: time="2025-06-01T22:31:52+02:00" level=info msg="running go-librespot 0.2.0" Jun 01 22:31:52 volumio3 go-librespot[1522]: time="2025-06-01T22:31:52+02:00" level=debug msg="app state loaded" Jun 01 22:31:52 volumio3 go-librespot[1522]: time="2025-06-01T22:31:52+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 22:31:52 volumio3 go-librespot[1522]: time="2025-06-01T22:31:52+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 01 22:31:52 volumio3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 01 22:31:52 volumio3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 01 22:31:52 volumio3 volumio[939]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS aarch64 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetVisibleSources Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:52 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 01 22:31:52 volumio3 volumio[939]: info: Received Get System Info Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 22:31:52 volumio3 volumio[939]: info: Discovery: Getting this device information Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:52 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:52 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:52 volumio3 volumio[939]: info: Listing playlists Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 01 22:31:52 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 01 22:31:53 volumio3 sudo[1530]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Joachim,password=Apfelmann2773,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,noserverino //192.168.178.1/FRITZ.NAS/USB1/Musik/Alben /mnt/NAS/My_Music Jun 01 22:31:53 volumio3 sudo[1530]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:53 volumio3 sudo[1530]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:53 volumio3 volumio[939]: info: Cannot mount NAS My_Music at system boot, trial number 2 ,retrying in 5 seconds Jun 01 22:31:53 volumio3 kernel: CIFS: Attempting to mount //192.168.178.1/FRITZ.NAS/USB1/Musik/Alben Jun 01 22:31:53 volumio3 kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Jun 01 22:31:53 volumio3 kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Jun 01 22:31:53 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:53 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:53 volumio3 volumio[939]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 01 22:31:53 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 01 22:31:54 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 01 22:31:54 volumio3 volumio[939]: info: Received Get System Info Jun 01 22:31:54 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 22:31:54 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 22:31:54 volumio3 volumio[939]: info: Discovery: Getting this device information Jun 01 22:31:54 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:54 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:54 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 22:31:54 volumio3 volumio-time-update[707]: volumio-time-update-util: Fetching time from Volumio... Jun 01 22:31:54 volumio3 volumio-time-update[707]: volumio-time-update-util: Date not found in response Jun 01 22:31:54 volumio3 volumio-time-update[707]: volumio-time-update-util: Retrying in 5 seconds... Jun 01 22:31:54 volumio3 sh[679]: eth0: leased 192.168.178.32 for 864000 seconds Jun 01 22:31:54 volumio3 dhcpcd[703]: eth0: leased 192.168.178.32 for 864000 seconds Jun 01 22:31:54 volumio3 sh[679]: eth0: adding route to 192.168.178.0/24 Jun 01 22:31:54 volumio3 sh[679]: eth0: adding default route via 192.168.178.1 Jun 01 22:31:54 volumio3 avahi-daemon[720]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.178.32. Jun 01 22:31:54 volumio3 dhcpcd[703]: eth0: adding route to 192.168.178.0/24 Jun 01 22:31:54 volumio3 avahi-daemon[720]: New relevant interface eth0.IPv4 for mDNS. Jun 01 22:31:54 volumio3 dhcpcd[703]: eth0: adding default route via 192.168.178.1 Jun 01 22:31:54 volumio3 avahi-daemon[720]: Registering new address record for 192.168.178.32 on eth0.IPv4. Jun 01 22:31:54 volumio3 volumio[939]: verbose: New Socket.io Connection to 192.168.178.32 from 192.168.178.22 UA: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:109.0) Gecko/20100101 Firefox/115.0 Engine version: 3 Transport: polling Total Clients: 6 Jun 01 22:31:54 volumio3 volumio[939]: verbose: New Socket.io Connection to 192.168.178.32 from 192.168.178.22 UA: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:109.0) Gecko/20100101 Firefox/115.0 Engine version: 3 Transport: polling Total Clients: 7 Jun 01 22:31:54 volumio3 ntpd[1039]: ntpd exiting on signal 15 (Terminated) Jun 01 22:31:54 volumio3 systemd[1]: Stopping Network Time Service... Jun 01 22:31:54 volumio3 systemd[1]: ntp.service: Succeeded. Jun 01 22:31:54 volumio3 systemd[1]: Stopped Network Time Service. Jun 01 22:31:54 volumio3 systemd[1]: Starting Network Time Service... Jun 01 22:31:54 volumio3 ntpd[1570]: ntpd 4.2.8p12@1.3728-o (1): Starting Jun 01 22:31:54 volumio3 ntpd[1570]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -c /run/ntp.conf.dhcp -u 103:103 Jun 01 22:31:54 volumio3 systemd[1]: Started Network Time Service. Jun 01 22:31:54 volumio3 ntpd[1576]: proto: precision = 0.352 usec (-21) Jun 01 22:31:54 volumio3 sh[679]: forked to background, child pid 1577 Jun 01 22:31:54 volumio3 ntpd[1576]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jun 01 22:31:54 volumio3 dhcpcd[703]: forked to background, child pid 1577 Jun 01 22:31:54 volumio3 ntpd[1576]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jun 01 22:31:54 volumio3 ntpd[1576]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 156 days ago Jun 01 22:31:54 volumio3 ntpd[1576]: Listen and drop on 0 v6wildcard [::]:123 Jun 01 22:31:54 volumio3 ntpd[1576]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jun 01 22:31:54 volumio3 ntpd[1576]: Listen normally on 2 lo 127.0.0.1:123 Jun 01 22:31:54 volumio3 ntpd[1576]: Listen normally on 3 eth0 192.168.178.32:123 Jun 01 22:31:54 volumio3 ntpd[1576]: Listening on routing socket on fd #20 for interface updates Jun 01 22:31:54 volumio3 ntpd[1576]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 01 22:31:54 volumio3 ntpd[1576]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 01 22:31:54 volumio3 ifplugd(eth0)[1049]: client: ifup: interface eth0 already configured Jun 01 22:31:54 volumio3 sh[679]: eth0=eth0 Jun 01 22:31:54 volumio3 ifplugd(eth0)[1049]: Program executed successfully. Jun 01 22:31:54 volumio3 volumio[939]: info: Initializing connection to go-librespot Websocket Jun 01 22:31:54 volumio3 volumio[939]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 01 22:31:55 volumio3 volumio[939]: info: Discovery: adding 7a46952c-fcef-432f-a37f-609d0db5995c Jun 01 22:31:55 volumio3 volumio[939]: info: Discovery: Found device Volumio3 Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:55 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:55 volumio3 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 01 22:31:55 volumio3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jun 01 22:31:55 volumio3 systemd[1]: Stopped go-librespot Daemon. Jun 01 22:31:55 volumio3 systemd[1]: Started go-librespot Daemon. Jun 01 22:31:55 volumio3 go-librespot[1782]: go-librespot daemon starting... Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=info msg="running go-librespot 0.2.0" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="app state loaded" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 01 22:31:55 volumio3 ntpd[1576]: Soliciting pool server 193.158.22.13 Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=info msg="zeroconf server listening on port 32921" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="obtained new client token: AACqf9RxRoLe5D2BNILOoxUEyeGvm2/P/qrBL93b1cGR3ZR0JDcXo2fC7oM6ELUxsmhzy3hat6yCjOhqMhBr5AjiXzMakJj8HFdNjU+wS9eAxYEMwebny3DFrG+jGB1XZTwOYYSWDaylufkVX44DBQUQLg+3kW/lGcD0+sM1KaiHD7BLwVkbjI8gtvyewo5xuaWwKdF1cLQr6IGYvoD5HcuvcemNsLYfD4GUoEi6zh0GBDgnNzEEMSCVwg==" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="completed keyexchange" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="completed challenge" Jun 01 22:31:55 volumio3 nmbd[1027]: [2025/06/01 22:31:55.628896, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 01 22:31:55 volumio3 nmbd[1027]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jun 01 22:31:55 volumio3 systemd[1]: Started Samba NMB Daemon. Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=info msg="authenticated AP as 31fmvpl3iblzjp2sj3gtx6kkszc4" Jun 01 22:31:55 volumio3 systemd[1]: Starting Samba Winbind Daemon... Jun 01 22:31:55 volumio3 winbindd[1801]: [2025/06/01 22:31:55.719652, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jun 01 22:31:55 volumio3 winbindd[1801]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jun 01 22:31:55 volumio3 winbindd[1801]: [2025/06/01 22:31:55.722685, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 01 22:31:55 volumio3 winbindd[1801]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jun 01 22:31:55 volumio3 systemd[1]: Started Samba Winbind Daemon. Jun 01 22:31:55 volumio3 systemd[1]: Starting Samba SMB Daemon... Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=info msg="authenticated Login5 as 31fmvpl3iblzjp2sj3gtx6kkszc4" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="initializing zeroconf session, username: 31fmvpl3iblzjp2sj3gtx6kkszc4" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="dealer connection opened" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=trace msg="starting accesspoint recv loop" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=trace msg="starting dealer recv loop" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=trace msg="received accesspoint ping" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="received connection id: MTRiOTAwOTAtYjA1ZC00ZDYyLTgwZTctYWY4YzgwZjdhM2I1K2RlYWxlcit0Y3A6Ly8wYWNhNWE2NC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQzZEOTNENjgxOTBDREFBNkNDQjRDNjYzMzZCRUIxNDM3RkMyOUI2NkIzM0FENURDRTU3QjJBOTI3QTlBM0M1Mg==" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=trace msg="received accesspoint pong ack" Jun 01 22:31:55 volumio3 smbd[1806]: [2025/06/01 22:31:55.868414, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 01 22:31:55 volumio3 systemd[1]: Started Samba SMB Daemon. Jun 01 22:31:55 volumio3 smbd[1806]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 01 22:31:55 volumio3 go-librespot[1782]: time="2025-06-01T22:31:55+02:00" level=debug msg="update volume to 65535/65535" Jun 01 22:31:55 volumio3 volumio[939]: verbose: New Socket.io Connection to 192.168.178.32 from 192.168.178.22 UA: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:109.0) Gecko/20100101 Firefox/115.0 Engine version: 3 Transport: polling Total Clients: 8 Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetVisibleSources Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:55 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:55 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 01 22:31:55 volumio3 volumio[939]: info: Received Get System Info Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 22:31:55 volumio3 volumio[939]: info: Discovery: Getting this device information Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:55 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:55 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:55 volumio3 volumio[939]: info: Listing playlists Jun 01 22:31:55 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jun 01 22:31:55 volumio3 volumio[939]: info: CoreStateMachine::getQueue Jun 01 22:31:55 volumio3 volumio[939]: info: CorePlayQueue::getQueue Jun 01 22:31:56 volumio3 ntpd[1576]: Soliciting pool server 85.215.166.214 Jun 01 22:31:56 volumio3 ntpd[1576]: Soliciting pool server 194.164.164.175 Jun 01 22:31:56 volumio3 volumio[939]: info: Volumio Network Manager: Network status updated: 1 Jun 01 22:31:56 volumio3 sudo[1830]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 01 22:31:56 volumio3 sudo[1830]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:56 volumio3 sudo[1830]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:56 volumio3 sudo[1833]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 01 22:31:56 volumio3 sudo[1833]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:56 volumio3 sudo[1833]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:56 volumio3 sudo[1836]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 01 22:31:56 volumio3 sudo[1836]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:56 volumio3 go-librespot[1782]: time="2025-06-01T22:31:56+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 01 22:31:56 volumio3 go-librespot[1782]: time="2025-06-01T22:31:56+02:00" level=trace msg="emitting websocket event: volume" Jun 01 22:31:56 volumio3 systemd[1]: Started UPnP Renderer front-end to MPD. Jun 01 22:31:56 volumio3 sudo[1836]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:56 volumio3 volumio[939]: info: Upmpdcli Daemon Started Jun 01 22:31:57 volumio3 volumio[1838]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 01 22:31:57 volumio3 volumio[939]: info: Adding plugin bluetooth to MyMusic Plugins Jun 01 22:31:57 volumio3 volumio[939]: info: Adding plugin multiroom to MyMusic Plugins Jun 01 22:31:57 volumio3 volumio[939]: info: Adding plugin metavolumio to MyMusic Plugins Jun 01 22:31:57 volumio3 volumio[939]: info: Adding plugin cd_controller to MyMusic Plugins Jun 01 22:31:57 volumio3 volumio[939]: info: Adding plugin qobuzconnect to MyMusic Plugins Jun 01 22:31:57 volumio3 volumio[939]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 01 22:31:57 volumio3 volumio[939]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 01 22:31:57 volumio3 ntpd[1576]: Soliciting pool server 217.91.44.17 Jun 01 22:31:57 volumio3 ntpd[1576]: Soliciting pool server 116.203.96.227 Jun 01 22:31:57 volumio3 ntpd[1576]: Soliciting pool server 178.63.52.50 Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 01 22:31:57 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 22:31:57 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 22:31:57 volumio3 volumio[939]: info: Starting MyVolumio Remote Streaming Endpoints Jun 01 22:31:57 volumio3 volumio[939]: info: MyVolumio login type: Token Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jun 01 22:31:57 volumio3 volumio[939]: info: Starting Streaming Service Transparent Proxy Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jun 01 22:31:57 volumio3 volumio[939]: info: Streaming services startup Jun 01 22:31:57 volumio3 volumio[939]: info: Starting Streaming Daemon Jun 01 22:31:57 volumio3 sudo[1861]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 01 22:31:57 volumio3 sudo[1861]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:57 volumio3 sudo[1861]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:57 volumio3 volumio[939]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jun 01 22:31:57 volumio3 volumio[939]: info: Initializing connection to go-librespot Websocket Jun 01 22:31:57 volumio3 volumio[939]: error: Cannot start Volumio Streaming Daemon Jun 01 22:31:57 volumio3 volumio[939]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 01 22:31:57 volumio3 volumio[939]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 01 22:31:57 volumio3 go-librespot[1782]: time="2025-06-01T22:31:57+02:00" level=debug msg="new websocket client" Jun 01 22:31:57 volumio3 volumio[939]: info: Connection to go-librespot Websocket established Jun 01 22:31:58 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 01 22:31:58 volumio3 volumio[939]: info: Received Get System Info Jun 01 22:31:58 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 22:31:58 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 22:31:58 volumio3 volumio[939]: info: Discovery: Getting this device information Jun 01 22:31:58 volumio3 volumio[939]: info: CoreCommandRouter::volumioGetState Jun 01 22:31:58 volumio3 volumio[939]: info: CorePlayQueue::getTrack 0 Jun 01 22:31:58 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 22:31:58 volumio3 sudo[1869]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Joachim,password=Apfelmann2773,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,noserverino //192.168.178.1/FRITZ.NAS/USB1/Musik/Alben /mnt/NAS/My_Music Jun 01 22:31:58 volumio3 sudo[1869]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:58 volumio3 kernel: CIFS: Attempting to mount //192.168.178.1/FRITZ.NAS/USB1/Musik/Alben Jun 01 22:31:58 volumio3 volumio[939]: STREAMING PROXY: Starting server on port 3245 Jun 01 22:31:58 volumio3 volumio[939]: Node JS runtime: 14 Jun 01 22:31:58 volumio3 volumio[939]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.812&uuid=17e62e4455c7533434561086b6719d54" http://updates.volumio.org/downloader-v1/track-device Jun 01 22:31:58 volumio3 volumio[939]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 01 22:31:58 volumio3 volumio[939]: Dload Upload Total Spent Left Speed Jun 01 22:31:58 volumio3 volumio[939]: [132B blob data] Jun 01 22:31:58 volumio3 volumio[939]: retrying in 5 seconds, trial 0 Jun 01 22:31:58 volumio3 volumio[939]: info: Volumio Calling Home Jun 01 22:31:58 volumio3 volumio[939]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jun 01 22:31:58 volumio3 volumio[939]: info: Volumio called home Jun 01 22:31:58 volumio3 ntpd[1576]: Soliciting pool server 172.104.134.72 Jun 01 22:31:58 volumio3 ntpd[1576]: Soliciting pool server 176.9.44.212 Jun 01 22:31:58 volumio3 ntpd[1576]: Soliciting pool server 109.123.244.54 Jun 01 22:31:58 volumio3 ntpd[1576]: Soliciting pool server 130.162.220.39 Jun 01 22:31:58 volumio3 volumio[1838]: ...............................++++ Jun 01 22:31:58 volumio3 volumio[939]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 01 22:31:58 volumio3 volumio[939]: info: MyVolumio login type: Token Jun 01 22:31:58 volumio3 volumio[939]: info: MyVolumio token set successfully Jun 01 22:31:58 volumio3 volumio[939]: info: MYVOLUMIO: Adding device Jun 01 22:31:58 volumio3 volumio[939]: info: MYVOLUMIO: Evaluating Server Jun 01 22:31:59 volumio3 volumio[939]: info: MyVolumio status changed Jun 01 22:31:59 volumio3 volumio[939]: info: Streaming services startup Jun 01 22:31:59 volumio3 volumio[939]: info: Starting Streaming Daemon Jun 01 22:31:59 volumio3 volumio[939]: info: Removing browser output: myVolumio user plan is not superstar Jun 01 22:31:59 volumio3 volumio[939]: info: Removing audio output: Jun 01 22:31:59 volumio3 volumio[939]: info: Stoppping Tunnel 1 Jun 01 22:31:59 volumio3 sudo[1906]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 01 22:31:59 volumio3 sudo[1906]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:59 volumio3 sudo[1909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jun 01 22:31:59 volumio3 sudo[1909]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:59 volumio3 sudo[1906]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:59 volumio3 volumio[939]: error: Cannot start Volumio Streaming Daemon Jun 01 22:31:59 volumio3 volumio[939]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 01 22:31:59 volumio3 volumio[939]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 01 22:31:59 volumio3 sudo[1909]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:59 volumio3 volumio[939]: info: Remote SSH Stopped Jun 01 22:31:59 volumio3 volumio-time-update[707]: volumio-time-update-util: Fetching time from Volumio... Jun 01 22:31:59 volumio3 volumio-time-update[707]: volumio-time-update-util: Setting system time to: 2025-06-01 22:31:58 Jun 01 22:31:59 volumio3 sudo[1916]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-06-01 22:31:58 Jun 01 22:31:59 volumio3 sudo[1916]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 22:31:59 volumio3 dbus-daemon[711]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.20' (uid=0 pid=1917 comm="timedatectl set-time 2025-06-01 22:31:58 ") Jun 01 22:31:59 volumio3 systemd[1]: Starting Time & Date Service... Jun 01 22:31:59 volumio3 dbus-daemon[711]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 01 22:31:59 volumio3 systemd[1]: Started Time & Date Service. Jun 01 22:31:58 volumio3 systemd-timedated[1918]: Changed local time to Sun Jun 1 22:31:58 2025 Jun 01 22:31:58 volumio3 sudo[1916]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:58 volumio3 volumio-time-update[707]: volumio-time-update-util: System time updated successfully. Jun 01 22:31:58 volumio3 systemd[1]: Started Volumio Time Update Utility. Jun 01 22:31:58 volumio3 systemd[1]: Reached target Multi-User System. Jun 01 22:31:58 volumio3 systemd[1]: Reached target Graphical Interface. Jun 01 22:31:58 volumio3 systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 01 22:31:58 volumio3 volumio[939]: error: Failed to ping endpoint us2.myvolumio.org : unknown error Jun 01 22:31:58 volumio3 volumio[939]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 01 22:31:58 volumio3 volumio[939]: Error: Unable to resolve or reject the same promise twice Jun 01 22:31:58 volumio3 volumio[939]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jun 01 22:31:58 volumio3 volumio[939]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Jun 01 22:31:58 volumio3 volumio[939]: at Socket.emit (events.js:327:22) Jun 01 22:31:58 volumio3 volumio[939]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 01 22:31:58 volumio3 volumio[939]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 01 22:31:58 volumio3 volumio[939]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 01 22:31:58 volumio3 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 01 22:31:58 volumio3 systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 01 22:31:58 volumio3 systemd[1]: Startup finished in 10.652s (kernel) + 16.477s (userspace) = 27.130s. Jun 01 22:31:58 volumio3 sudo[1869]: pam_unix(sudo:session): session closed for user root Jun 01 22:31:58 volumio3 ntpd[1576]: Soliciting pool server 176.9.157.155 Jun 01 22:31:58 volumio3 ntpd[1576]: Soliciting pool server 162.159.200.1 Jun 01 22:31:58 volumio3 ntpd[1576]: Soliciting pool server 157.230.98.101 Jun 01 22:31:58 volumio3 sudo[1930]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-01 22:30 Jun 01 22:31:58 volumio3 sudo[1930]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"