-- Logs begin at Thu 2024-08-29 19:51:06 PDT, end at Thu 2024-08-29 19:51:48 PDT. -- Aug 29 19:51:06 donquixotevolumio kernel: Booting Linux on physical CPU 0x0 Aug 29 19:51:06 donquixotevolumio kernel: Linux version 6.1.77-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1730 SMP Thu Feb 8 15:22:02 GMT 2024 Aug 29 19:51:06 donquixotevolumio kernel: CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d Aug 29 19:51:06 donquixotevolumio kernel: CPU: div instructions available: patching division code Aug 29 19:51:06 donquixotevolumio kernel: CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache Aug 29 19:51:06 donquixotevolumio kernel: OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.5 Aug 29 19:51:06 donquixotevolumio kernel: random: crng init done Aug 29 19:51:06 donquixotevolumio kernel: Memory policy: Data cache writealloc Aug 29 19:51:06 donquixotevolumio kernel: Reserved memory: created CMA memory pool at 0x000000002a000000, size 64 MiB Aug 29 19:51:06 donquixotevolumio kernel: OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool Aug 29 19:51:06 donquixotevolumio kernel: Zone ranges: Aug 29 19:51:06 donquixotevolumio kernel: DMA [mem 0x0000000000000000-0x000000002fffffff] Aug 29 19:51:06 donquixotevolumio kernel: Normal empty Aug 29 19:51:06 donquixotevolumio kernel: HighMem [mem 0x0000000030000000-0x00000000fbffffff] Aug 29 19:51:06 donquixotevolumio kernel: Movable zone start for each node Aug 29 19:51:06 donquixotevolumio kernel: Early memory node ranges Aug 29 19:51:06 donquixotevolumio kernel: node 0: [mem 0x0000000000000000-0x0000000037ffffff] Aug 29 19:51:06 donquixotevolumio kernel: node 0: [mem 0x0000000040000000-0x00000000fbffffff] Aug 29 19:51:06 donquixotevolumio kernel: Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff] Aug 29 19:51:06 donquixotevolumio kernel: percpu: Embedded 17 pages/cpu s37012 r8192 d24428 u69632 Aug 29 19:51:06 donquixotevolumio kernel: pcpu-alloc: s37012 r8192 d24428 u69632 alloc=17*4096 Aug 29 19:51:06 donquixotevolumio kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Aug 29 19:51:06 donquixotevolumio kernel: Built 1 zonelists, mobility grouping on. Total pages: 997696 Aug 29 19:51:06 donquixotevolumio kernel: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=D8:3A:DD:63:F8:26 vc_mem.mem_base=0x3ec00000 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=ttyS0,115200 console=tty1 imgpart=UUID=7462f9ec-50f6-4f55-9f22-79cca1bee42a imgfile=/volumio_current.sqsh bootpart=UUID=6B37-2179 datapart=UUID=05aa9627-e829-40c7-ad33-94111ba2ebbc 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 Aug 29 19:51:06 donquixotevolumio kernel: Unknown kernel command line parameters "splash nodebug imgpart=UUID=7462f9ec-50f6-4f55-9f22-79cca1bee42a imgfile=/volumio_current.sqsh bootpart=UUID=6B37-2179 datapart=UUID=05aa9627-e829-40c7-ad33-94111ba2ebbc uuidconfig=cmdline.txt pcie_aspm=off bootdelay=7 use_kmsg=no", will be passed to user space. Aug 29 19:51:06 donquixotevolumio kernel: Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Aug 29 19:51:06 donquixotevolumio kernel: software IO TLB: area num 4. Aug 29 19:51:06 donquixotevolumio kernel: software IO TLB: mapped [mem 0x0000000023c90000-0x0000000027c90000] (64MB) Aug 29 19:51:06 donquixotevolumio kernel: Memory: 3796700K/3997696K available (10240K kernel code, 1504K rwdata, 3388K rodata, 2048K init, 638K bss, 135460K reserved, 65536K cma-reserved, 3211264K highmem) Aug 29 19:51:06 donquixotevolumio kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Aug 29 19:51:06 donquixotevolumio kernel: ftrace: allocating 37251 entries in 110 pages Aug 29 19:51:06 donquixotevolumio kernel: ftrace: allocated 110 pages with 5 groups Aug 29 19:51:06 donquixotevolumio kernel: trace event string verifier disabled Aug 29 19:51:06 donquixotevolumio kernel: rcu: Hierarchical RCU implementation. Aug 29 19:51:06 donquixotevolumio kernel: Rude variant of Tasks RCU enabled. Aug 29 19:51:06 donquixotevolumio kernel: Tracing variant of Tasks RCU enabled. Aug 29 19:51:06 donquixotevolumio kernel: rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Aug 29 19:51:06 donquixotevolumio kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Aug 29 19:51:06 donquixotevolumio kernel: GIC: Using split EOI/Deactivate mode Aug 29 19:51:06 donquixotevolumio kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Aug 29 19:51:06 donquixotevolumio kernel: arch_timer: cp15 timer(s) running at 54.00MHz (phys). Aug 29 19:51:06 donquixotevolumio kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns Aug 29 19:51:06 donquixotevolumio kernel: sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns Aug 29 19:51:06 donquixotevolumio kernel: Switching to timer-based delay loop, resolution 18ns Aug 29 19:51:06 donquixotevolumio kernel: Console: colour dummy device 80x30 Aug 29 19:51:06 donquixotevolumio kernel: printk: console [tty1] enabled Aug 29 19:51:06 donquixotevolumio kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000) Aug 29 19:51:06 donquixotevolumio kernel: CPU: Testing write buffer coherency: ok Aug 29 19:51:06 donquixotevolumio kernel: CPU0: Spectre BHB: enabling loop workaround for all CPUs Aug 29 19:51:06 donquixotevolumio kernel: pid_max: default: 32768 minimum: 301 Aug 29 19:51:06 donquixotevolumio kernel: LSM: Security Framework initializing Aug 29 19:51:06 donquixotevolumio kernel: Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: cgroup: Disabling memory control group subsystem Aug 29 19:51:06 donquixotevolumio kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Aug 29 19:51:06 donquixotevolumio kernel: cblist_init_generic: Setting adjustable number of callback queues. Aug 29 19:51:06 donquixotevolumio kernel: cblist_init_generic: Setting shift to 2 and lim to 1. Aug 29 19:51:06 donquixotevolumio kernel: cblist_init_generic: Setting adjustable number of callback queues. Aug 29 19:51:06 donquixotevolumio kernel: cblist_init_generic: Setting shift to 2 and lim to 1. Aug 29 19:51:06 donquixotevolumio kernel: Setting up static identity map for 0x200000 - 0x20003c Aug 29 19:51:06 donquixotevolumio kernel: rcu: Hierarchical SRCU implementation. Aug 29 19:51:06 donquixotevolumio kernel: rcu: Max phase no-delay instances is 1000. Aug 29 19:51:06 donquixotevolumio kernel: smp: Bringing up secondary CPUs ... Aug 29 19:51:06 donquixotevolumio kernel: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Aug 29 19:51:06 donquixotevolumio kernel: CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Aug 29 19:51:06 donquixotevolumio kernel: CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Aug 29 19:51:06 donquixotevolumio kernel: smp: Brought up 1 node, 4 CPUs Aug 29 19:51:06 donquixotevolumio kernel: SMP: Total of 4 processors activated (432.00 BogoMIPS). Aug 29 19:51:06 donquixotevolumio kernel: CPU: All CPU(s) started in HYP mode. Aug 29 19:51:06 donquixotevolumio kernel: CPU: Virtualization extensions available. Aug 29 19:51:06 donquixotevolumio kernel: devtmpfs: initialized Aug 29 19:51:06 donquixotevolumio kernel: VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0 Aug 29 19:51:06 donquixotevolumio kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Aug 29 19:51:06 donquixotevolumio kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: pinctrl core: initialized pinctrl subsystem Aug 29 19:51:06 donquixotevolumio kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Aug 29 19:51:06 donquixotevolumio kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Aug 29 19:51:06 donquixotevolumio kernel: audit: initializing netlink subsys (disabled) Aug 29 19:51:06 donquixotevolumio kernel: audit: type=2000 audit(0.020:1): state=initialized audit_enabled=0 res=1 Aug 29 19:51:06 donquixotevolumio kernel: thermal_sys: Registered thermal governor 'step_wise' Aug 29 19:51:06 donquixotevolumio kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Aug 29 19:51:06 donquixotevolumio kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Aug 29 19:51:06 donquixotevolumio kernel: Serial: AMBA PL011 UART driver Aug 29 19:51:06 donquixotevolumio kernel: bcm2835-mbox fe00b880.mailbox: mailbox enabled Aug 29 19:51:06 donquixotevolumio kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2023-10-17T15:39:16, variant start Aug 29 19:51:06 donquixotevolumio kernel: raspberrypi-firmware soc:firmware: Firmware hash is 30f0c5e4d076da3ab4f341d88e7d505760b93ad7 Aug 29 19:51:06 donquixotevolumio kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Aug 29 19:51:06 donquixotevolumio kernel: bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 Aug 29 19:51:06 donquixotevolumio kernel: SCSI subsystem initialized Aug 29 19:51:06 donquixotevolumio kernel: usbcore: registered new interface driver usbfs Aug 29 19:51:06 donquixotevolumio kernel: usbcore: registered new interface driver hub Aug 29 19:51:06 donquixotevolumio kernel: usbcore: registered new device driver usb Aug 29 19:51:06 donquixotevolumio kernel: usb_phy_generic phy: supply vcc not found, using dummy regulator Aug 29 19:51:06 donquixotevolumio kernel: pps_core: LinuxPPS API ver. 1 registered Aug 29 19:51:06 donquixotevolumio kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti Aug 29 19:51:06 donquixotevolumio kernel: PTP clock support registered Aug 29 19:51:06 donquixotevolumio kernel: vgaarb: loaded Aug 29 19:51:06 donquixotevolumio kernel: clocksource: Switched to clocksource arch_sys_counter Aug 29 19:51:06 donquixotevolumio kernel: VFS: Disk quotas dquot_6.6.0 Aug 29 19:51:06 donquixotevolumio kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Aug 29 19:51:06 donquixotevolumio kernel: FS-Cache: Loaded Aug 29 19:51:06 donquixotevolumio kernel: CacheFiles: Loaded Aug 29 19:51:06 donquixotevolumio kernel: NET: Registered PF_INET protocol family Aug 29 19:51:06 donquixotevolumio kernel: IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: TCP bind hash table entries: 8192 (order: 5, 131072 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: TCP: Hash tables configured (established 8192 bind 8192) Aug 29 19:51:06 donquixotevolumio kernel: UDP hash table entries: 512 (order: 2, 16384 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) Aug 29 19:51:06 donquixotevolumio kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Aug 29 19:51:06 donquixotevolumio kernel: RPC: Registered named UNIX socket transport module. Aug 29 19:51:06 donquixotevolumio kernel: RPC: Registered udp transport module. Aug 29 19:51:06 donquixotevolumio kernel: RPC: Registered tcp transport module. Aug 29 19:51:06 donquixotevolumio kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Aug 29 19:51:06 donquixotevolumio kernel: PCI: CLS 0 bytes, default 64 Aug 29 19:51:06 donquixotevolumio kernel: Trying to unpack rootfs image as initramfs... Aug 29 19:51:06 donquixotevolumio kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available Aug 29 19:51:06 donquixotevolumio kernel: Initialise system trusted keyrings Aug 29 19:51:06 donquixotevolumio kernel: workingset: timestamp_bits=14 max_order=20 bucket_order=6 Aug 29 19:51:06 donquixotevolumio kernel: zbud: loaded Aug 29 19:51:06 donquixotevolumio kernel: NFS: Registering the id_resolver key type Aug 29 19:51:06 donquixotevolumio kernel: Key type id_resolver registered Aug 29 19:51:06 donquixotevolumio kernel: Key type id_legacy registered Aug 29 19:51:06 donquixotevolumio kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Aug 29 19:51:06 donquixotevolumio kernel: nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Aug 29 19:51:06 donquixotevolumio kernel: Key type asymmetric registered Aug 29 19:51:06 donquixotevolumio kernel: Asymmetric key parser 'x509' registered Aug 29 19:51:06 donquixotevolumio kernel: bounce: pool size: 64 pages Aug 29 19:51:06 donquixotevolumio kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) Aug 29 19:51:06 donquixotevolumio kernel: io scheduler mq-deadline registered Aug 29 19:51:06 donquixotevolumio kernel: io scheduler kyber registered Aug 29 19:51:06 donquixotevolumio kernel: brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: Aug 29 19:51:06 donquixotevolumio kernel: brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] Aug 29 19:51:06 donquixotevolumio kernel: brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 Aug 29 19:51:06 donquixotevolumio kernel: brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00ffffffff -> 0x0400000000 Aug 29 19:51:06 donquixotevolumio kernel: brcm-pcie fd500000.pcie: setting SCB_ACCESS_EN, READ_UR_MODE, MAX_BURST_SIZE Aug 29 19:51:06 donquixotevolumio kernel: brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 Aug 29 19:51:06 donquixotevolumio kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Aug 29 19:51:06 donquixotevolumio kernel: pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:00:00.0: PME# supported from D0 D3hot Aug 29 19:51:06 donquixotevolumio kernel: PCI: bus0: Fast back to back transfers disabled Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring Aug 29 19:51:06 donquixotevolumio kernel: pci_bus 0000:01: supply vpcie3v3 not found, using dummy regulator Aug 29 19:51:06 donquixotevolumio kernel: pci_bus 0000:01: supply vpcie3v3aux not found, using dummy regulator Aug 29 19:51:06 donquixotevolumio kernel: pci_bus 0000:01: supply vpcie12v not found, using dummy regulator Aug 29 19:51:06 donquixotevolumio kernel: brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:01:00.0: PME# supported from D0 D3hot Aug 29 19:51:06 donquixotevolumio kernel: PCI: bus1: Fast back to back transfers disabled Aug 29 19:51:06 donquixotevolumio kernel: pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01 Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:00:00.0: PCI bridge to [bus 01] Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:00:00.0: Max Payload Size set to 256/ 512 (was 128), Max Read Rq 512 Aug 29 19:51:06 donquixotevolumio kernel: pci 0000:01:00.0: Max Payload Size set to 256/ 256 (was 128), Max Read Rq 512 Aug 29 19:51:06 donquixotevolumio kernel: pcieport 0000:00:00.0: enabling device (0000 -> 0002) Aug 29 19:51:06 donquixotevolumio kernel: pcieport 0000:00:00.0: PME: Signaling with IRQ 45 Aug 29 19:51:06 donquixotevolumio kernel: bcm2708_fb soc:fb: FB found 1 display(s) Aug 29 19:51:06 donquixotevolumio kernel: Console: switching to colour frame buffer device 80x30 Aug 29 19:51:06 donquixotevolumio kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Aug 29 19:51:06 donquixotevolumio kernel: iproc-rng200 fe104000.rng: hwrng registered Aug 29 19:51:06 donquixotevolumio kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Aug 29 19:51:06 donquixotevolumio kernel: brd: module loaded Aug 29 19:51:06 donquixotevolumio kernel: loop: module loaded Aug 29 19:51:06 donquixotevolumio kernel: Loading iSCSI transport class v2.0-870. Aug 29 19:51:06 donquixotevolumio kernel: bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 Aug 29 19:51:06 donquixotevolumio kernel: Freeing initrd memory: 14316K Aug 29 19:51:06 donquixotevolumio kernel: unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus Aug 29 19:51:06 donquixotevolumio kernel: usbcore: registered new device driver r8152-cfgselector Aug 29 19:51:06 donquixotevolumio kernel: usbcore: registered new interface driver r8152 Aug 29 19:51:06 donquixotevolumio kernel: usbcore: registered new interface driver lan78xx Aug 29 19:51:06 donquixotevolumio kernel: usbcore: registered new interface driver smsc95xx Aug 29 19:51:06 donquixotevolumio kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Aug 29 19:51:06 donquixotevolumio kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 Aug 29 19:51:06 donquixotevolumio kernel: xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0b00040000000890 Aug 29 19:51:06 donquixotevolumio kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Aug 29 19:51:06 donquixotevolumio kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Aug 29 19:51:06 donquixotevolumio kernel: xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Aug 29 19:51:06 donquixotevolumio kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.01 Aug 29 19:51:06 donquixotevolumio kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Aug 29 19:51:06 donquixotevolumio kernel: usb usb1: Product: xHCI Host Controller Aug 29 19:51:06 donquixotevolumio kernel: usb usb1: Manufacturer: Linux 6.1.77-v7l+ xhci-hcd Aug 29 19:51:06 donquixotevolumio kernel: usb usb1: SerialNumber: 0000:01:00.0 Aug 29 19:51:06 donquixotevolumio kernel: hub 1-0:1.0: USB hub found Aug 29 19:51:06 donquixotevolumio kernel: hub 1-0:1.0: 1 port detected Aug 29 19:51:06 donquixotevolumio kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.01 Aug 29 19:51:06 donquixotevolumio kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Aug 29 19:51:06 donquixotevolumio kernel: usb usb2: Product: xHCI Host Controller Aug 29 19:51:06 donquixotevolumio kernel: usb usb2: Manufacturer: Linux 6.1.77-v7l+ xhci-hcd Aug 29 19:51:06 donquixotevolumio kernel: usb usb2: SerialNumber: 0000:01:00.0 Aug 29 19:51:06 donquixotevolumio kernel: hub 2-0:1.0: USB hub found Aug 29 19:51:06 donquixotevolumio kernel: hub 2-0:1.0: 4 ports detected Aug 29 19:51:06 donquixotevolumio kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Aug 29 19:51:06 donquixotevolumio kernel: dwc_otg: FIQ enabled Aug 29 19:51:06 donquixotevolumio kernel: dwc_otg: NAK holdoff enabled Aug 29 19:51:06 donquixotevolumio kernel: dwc_otg: FIQ split-transaction FSM enabled Aug 29 19:51:06 donquixotevolumio kernel: Module dwc_common_port init Aug 29 19:51:06 donquixotevolumio kernel: usbcore: registered new interface driver uas Aug 29 19:51:06 donquixotevolumio kernel: usbcore: registered new interface driver usb-storage Aug 29 19:51:06 donquixotevolumio kernel: mousedev: PS/2 mouse device common for all mice Aug 29 19:51:06 donquixotevolumio kernel: sdhci: Secure Digital Host Controller Interface driver Aug 29 19:51:06 donquixotevolumio kernel: sdhci: Copyright(c) Pierre Ossman Aug 29 19:51:06 donquixotevolumio kernel: sdhci-pltfm: SDHCI platform and OF driver helper Aug 29 19:51:06 donquixotevolumio kernel: ledtrig-cpu: registered to indicate activity on CPUs Aug 29 19:51:06 donquixotevolumio kernel: hid: raw HID events driver (C) Jiri Kosina Aug 29 19:51:06 donquixotevolumio kernel: usbcore: registered new interface driver usbhid Aug 29 19:51:06 donquixotevolumio kernel: usbhid: USB HID core driver Aug 29 19:51:06 donquixotevolumio kernel: Initializing XFRM netlink socket Aug 29 19:51:06 donquixotevolumio kernel: NET: Registered PF_PACKET protocol family Aug 29 19:51:06 donquixotevolumio kernel: Key type dns_resolver registered Aug 29 19:51:06 donquixotevolumio kernel: Registering SWP/SWPB emulation handler Aug 29 19:51:06 donquixotevolumio kernel: registered taskstats version 1 Aug 29 19:51:06 donquixotevolumio kernel: Loading compiled-in X.509 certificates Aug 29 19:51:06 donquixotevolumio kernel: Key type .fscrypt registered Aug 29 19:51:06 donquixotevolumio kernel: Key type fscrypt-provisioning registered Aug 29 19:51:06 donquixotevolumio kernel: uart-pl011 fe201000.serial: there is not valid maps for state default Aug 29 19:51:06 donquixotevolumio kernel: uart-pl011 fe201000.serial: cts_event_workaround enabled Aug 29 19:51:06 donquixotevolumio kernel: fe201000.serial: ttyAMA1 at MMIO 0xfe201000 (irq = 51, base_baud = 0) is a PL011 rev2 Aug 29 19:51:06 donquixotevolumio kernel: serial serial0: tty port ttyAMA1 registered Aug 29 19:51:06 donquixotevolumio kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Aug 29 19:51:06 donquixotevolumio kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Aug 29 19:51:06 donquixotevolumio kernel: mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 Aug 29 19:51:06 donquixotevolumio kernel: mmc-bcm2835 fe300000.mmcnr: DMA channel allocated Aug 29 19:51:06 donquixotevolumio kernel: of_cfs_init Aug 29 19:51:06 donquixotevolumio kernel: of_cfs_init: OK Aug 29 19:51:06 donquixotevolumio kernel: mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA Aug 29 19:51:06 donquixotevolumio kernel: Freeing unused kernel image (initmem) memory: 2048K Aug 29 19:51:06 donquixotevolumio kernel: Run /init as init process Aug 29 19:51:06 donquixotevolumio kernel: with arguments: Aug 29 19:51:06 donquixotevolumio kernel: /init Aug 29 19:51:06 donquixotevolumio kernel: splash Aug 29 19:51:06 donquixotevolumio kernel: nodebug Aug 29 19:51:06 donquixotevolumio kernel: with environment: Aug 29 19:51:06 donquixotevolumio kernel: HOME=/ Aug 29 19:51:06 donquixotevolumio kernel: TERM=linux Aug 29 19:51:06 donquixotevolumio kernel: imgpart=UUID=7462f9ec-50f6-4f55-9f22-79cca1bee42a Aug 29 19:51:06 donquixotevolumio kernel: imgfile=/volumio_current.sqsh Aug 29 19:51:06 donquixotevolumio kernel: bootpart=UUID=6B37-2179 Aug 29 19:51:06 donquixotevolumio kernel: datapart=UUID=05aa9627-e829-40c7-ad33-94111ba2ebbc Aug 29 19:51:06 donquixotevolumio kernel: uuidconfig=cmdline.txt Aug 29 19:51:06 donquixotevolumio kernel: pcie_aspm=off Aug 29 19:51:06 donquixotevolumio kernel: bootdelay=7 Aug 29 19:51:06 donquixotevolumio kernel: use_kmsg=no Aug 29 19:51:06 donquixotevolumio kernel: mmc1: new high speed SDIO card at address 0001 Aug 29 19:51:06 donquixotevolumio kernel: mmc0: new ultra high speed DDR50 SDHC card at address 5048 Aug 29 19:51:06 donquixotevolumio kernel: mmcblk0: mmc0:5048 SD32G 28.8 GiB Aug 29 19:51:06 donquixotevolumio kernel: mmcblk0: p1 p2 p3 Aug 29 19:51:06 donquixotevolumio kernel: mmcblk0: mmc0:5048 SD32G 28.8 GiB Aug 29 19:51:06 donquixotevolumio kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd Aug 29 19:51:06 donquixotevolumio kernel: usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 Aug 29 19:51:06 donquixotevolumio kernel: usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Aug 29 19:51:06 donquixotevolumio kernel: usb 1-1: Product: USB2.0 Hub Aug 29 19:51:06 donquixotevolumio kernel: hub 1-1:1.0: USB hub found Aug 29 19:51:06 donquixotevolumio kernel: hub 1-1:1.0: 4 ports detected Aug 29 19:51:06 donquixotevolumio kernel: fuse: init (API version 7.37) Aug 29 19:51:06 donquixotevolumio kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Aug 29 19:51:06 donquixotevolumio kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Aug 29 19:51:06 donquixotevolumio kernel: EXT4-fs (mmcblk0p2): recovery complete Aug 29 19:51:06 donquixotevolumio kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none. Aug 29 19:51:06 donquixotevolumio kernel: loop0: detected capacity change from 0 to 979240 Aug 29 19:51:06 donquixotevolumio kernel: EXT4-fs (mmcblk0p3): recovery complete Aug 29 19:51:06 donquixotevolumio kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Quota mode: none. Aug 29 19:51:06 donquixotevolumio systemd[1]: System time before build time, advancing clock. Aug 29 19:51:06 donquixotevolumio kernel: NET: Registered PF_INET6 protocol family Aug 29 19:51:06 donquixotevolumio kernel: Segment Routing with IPv6 Aug 29 19:51:06 donquixotevolumio kernel: In-situ OAM (IOAM) with IPv6 Aug 29 19:51:06 donquixotevolumio 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) Aug 29 19:51:06 donquixotevolumio systemd[1]: Detected architecture arm. Aug 29 19:51:06 donquixotevolumio systemd[1]: Set hostname to . Aug 29 19:51:06 donquixotevolumio 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. Aug 29 19:51:06 donquixotevolumio systemd[1]: Listening on RPCbind Server Activation Socket. Aug 29 19:51:06 donquixotevolumio systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. Aug 29 19:51:06 donquixotevolumio systemd[1]: Created slice system-getty.slice. Aug 29 19:51:06 donquixotevolumio systemd[1]: Listening on fsck to fsckd communication Socket. Aug 29 19:51:06 donquixotevolumio systemd[1]: Started Forward Password Requests to Wall Directory Watch. Aug 29 19:51:06 donquixotevolumio systemd[1]: Created slice system-systemd\x2dfsck.slice. Aug 29 19:51:06 donquixotevolumio kernel: i2c_dev: i2c /dev entries driver Aug 29 19:51:06 donquixotevolumio systemd-journald[321]: Journal started Aug 29 19:51:06 donquixotevolumio systemd-journald[321]: Runtime journal (/run/log/journal/32836d460d421189c56ead0a6628f62c) is 3.7M, max 30.0M, 26.2M free. Aug 29 19:51:06 donquixotevolumio systemd-modules-load[315]: Inserted module 'i2c_dev' Aug 29 19:51:06 donquixotevolumio fake-hwclock[318]: Fri Aug 30 02:51:06 UTC 2024 Aug 29 19:51:06 donquixotevolumio systemd[1]: dynamicswap.service: Succeeded. Aug 29 19:51:06 donquixotevolumio systemd[1]: Started Apply Kernel Variables. Aug 29 19:51:06 donquixotevolumio systemd[1]: Started Create Static Device Nodes in /dev. Aug 29 19:51:06 donquixotevolumio systemd[1]: Starting udev Kernel Device Manager... Aug 29 19:51:06 donquixotevolumio systemd[1]: Reached target Local File Systems (Pre). Aug 29 19:51:06 donquixotevolumio systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Aug 29 19:51:06 donquixotevolumio systemd[1]: Mounting /var/log... Aug 29 19:51:06 donquixotevolumio systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Aug 29 19:51:06 donquixotevolumio systemd[1]: Mounting /tmp... Aug 29 19:51:06 donquixotevolumio systemd[1]: Mounting /var/spool/cups... Aug 29 19:51:06 donquixotevolumio systemd[1]: Started udev Coldplug all Devices. Aug 29 19:51:06 donquixotevolumio systemd[1]: Mounted /var/log. Aug 29 19:51:06 donquixotevolumio systemd[1]: Mounted /tmp. Aug 29 19:51:06 donquixotevolumio systemd[1]: Starting Flush Journal to Persistent Storage... Aug 29 19:51:06 donquixotevolumio systemd[1]: Starting Helper to synchronize boot up for ifupdown... Aug 29 19:51:06 donquixotevolumio systemd[1]: Mounted /var/spool/cups. Aug 29 19:51:06 donquixotevolumio systemd-udevd[343]: Network interface NamePolicy= disabled on kernel command line, ignoring. Aug 29 19:51:06 donquixotevolumio systemd[1]: Mounting /var/spool/cups/tmp... Aug 29 19:51:06 donquixotevolumio systemd[1]: Mounted /var/spool/cups/tmp. Aug 29 19:51:06 donquixotevolumio systemd[1]: Started Helper to synchronize boot up for ifupdown. Aug 29 19:51:06 donquixotevolumio systemd-journald[321]: Runtime journal (/run/log/journal/32836d460d421189c56ead0a6628f62c) is 3.7M, max 30.0M, 26.2M free. Aug 29 19:51:06 donquixotevolumio systemd[1]: Started Flush Journal to Persistent Storage. Aug 29 19:51:06 donquixotevolumio systemd[1]: Started udev Kernel Device Manager. Aug 29 19:51:06 donquixotevolumio systemd[1]: Starting Show Plymouth Boot Screen... Aug 29 19:51:06 donquixotevolumio systemd[1]: plymouth-start.service: Succeeded. Aug 29 19:51:06 donquixotevolumio systemd[1]: Started Show Plymouth Boot Screen. Aug 29 19:51:06 donquixotevolumio systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Aug 29 19:51:06 donquixotevolumio systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Aug 29 19:51:06 donquixotevolumio systemd[1]: Reached target Local Encrypted Volumes. Aug 29 19:51:06 donquixotevolumio systemd[1]: Reached target Paths. Aug 29 19:51:06 donquixotevolumio systemd-udevd[360]: Using default interface naming scheme 'v240'. Aug 29 19:51:06 donquixotevolumio systemd-udevd[360]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Aug 29 19:51:06 donquixotevolumio kernel: mc: Linux media interface: v0.10 Aug 29 19:51:06 donquixotevolumio kernel: rpi-gpiomem fe200000.gpiomem: window base 0xfe200000 size 0x00001000 Aug 29 19:51:06 donquixotevolumio kernel: rpi-gpiomem fe200000.gpiomem: initialised 1 regions as /dev/gpiomem Aug 29 19:51:07 donquixotevolumio systemd[1]: Found device /dev/disk/by-uuid/6B37-2179. Aug 29 19:51:07 donquixotevolumio kernel: videodev: Linux video capture interface: v2.00 Aug 29 19:51:07 donquixotevolumio kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Aug 29 19:51:07 donquixotevolumio systemd[1]: Starting File System Check on /dev/disk/by-uuid/6B37-2179... Aug 29 19:51:07 donquixotevolumio kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Aug 29 19:51:07 donquixotevolumio kernel: [vc_sm_connected_init]: start Aug 29 19:51:07 donquixotevolumio kernel: [vc_sm_connected_init]: installed successfully Aug 29 19:51:07 donquixotevolumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Aug 29 19:51:07 donquixotevolumio kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Aug 29 19:51:07 donquixotevolumio systemd-udevd[365]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Aug 29 19:51:07 donquixotevolumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Aug 29 19:51:07 donquixotevolumio kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Aug 29 19:51:07 donquixotevolumio kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. Aug 29 19:51:07 donquixotevolumio kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Aug 29 19:51:07 donquixotevolumio systemd-fsck[421]: fsck.fat 4.1 (2017-01-24) Aug 29 19:51:07 donquixotevolumio systemd-fsck[421]: 0x25: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Aug 29 19:51:07 donquixotevolumio systemd-fsck[421]: Automatically removing dirty bit. Aug 29 19:51:07 donquixotevolumio systemd-fsck[421]: Unexpected long filename sequence number (2 vs. expected 1). Aug 29 19:51:07 donquixotevolumio systemd-fsck[421]: It could be that just the number is wrong Aug 29 19:51:07 donquixotevolumio systemd-fsck[421]: if "network-confi" seems to match "g". Aug 29 19:51:07 donquixotevolumio systemd-fsck[421]: Not auto-correcting this. Aug 29 19:51:07 donquixotevolumio systemd-fsck[421]: Performing changes. Aug 29 19:51:07 donquixotevolumio systemd-fsck[421]: /dev/mmcblk0p1: 374 files, 33668/46774 clusters Aug 29 19:51:07 donquixotevolumio systemd[1]: Started File System Check on /dev/disk/by-uuid/6B37-2179. Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Aug 29 19:51:07 donquixotevolumio kernel: rpivid feb10000.codec: Device registered as /dev/video19 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Aug 29 19:51:07 donquixotevolumio kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Aug 29 19:51:07 donquixotevolumio kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Aug 29 19:51:07 donquixotevolumio kernel: cfg80211: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Aug 29 19:51:07 donquixotevolumio kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Aug 29 19:51:07 donquixotevolumio kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Aug 29 19:51:08 donquixotevolumio kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Aug 29 19:51:08 donquixotevolumio kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Aug 29 19:51:08 donquixotevolumio kernel: usbcore: registered new interface driver brcmfmac Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: Core ver 2.22 Aug 29 19:51:08 donquixotevolumio kernel: NET: Registered PF_BLUETOOTH protocol family Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: HCI device and connection manager initialized Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: HCI socket layer initialized Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: L2CAP socket layer initialized Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: SCO socket layer initialized Aug 29 19:51:08 donquixotevolumio 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 Aug 29 19:51:08 donquixotevolumio systemd-udevd[353]: Using default interface naming scheme 'v240'. Aug 29 19:51:08 donquixotevolumio systemd-udevd[353]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Aug 29 19:51:08 donquixotevolumio kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Aug 29 19:51:08 donquixotevolumio kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: HCI UART driver ver 2.3 Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: HCI UART protocol H4 registered Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: HCI UART protocol Broadcom registered Aug 29 19:51:08 donquixotevolumio kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Aug 29 19:51:08 donquixotevolumio kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Aug 29 19:51:08 donquixotevolumio kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Aug 29 19:51:08 donquixotevolumio kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Aug 29 19:51:08 donquixotevolumio kernel: uart-pl011 fe201000.serial: no DMA platform data Aug 29 19:51:08 donquixotevolumio systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Aug 29 19:51:08 donquixotevolumio systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Aug 29 19:51:08 donquixotevolumio systemd[1]: Mounting /boot... Aug 29 19:51:08 donquixotevolumio systemd[1]: Started File System Check Daemon to report status. Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: hci0: BCM: chip id 107 Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: hci0: BCM: features 0x2f Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: hci0: BCM4345C0 Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Aug 29 19:51:08 donquixotevolumio kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Aug 29 19:51:08 donquixotevolumio kernel: wm8804 1-003b: revision E Aug 29 19:51:08 donquixotevolumio systemd[1]: Mounted /boot. Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in /sys/subsystem/net/devices/wlan0 being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in Huge Pages File System being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting Show Plymouth Boot Screen... Aug 29 19:51:09 donquixotevolumio systemd[1]: Reached target Local File Systems. Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting Raise network interfaces... Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting Preprocess NFS configuration... Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Aug 29 19:51:09 donquixotevolumio systemd[1]: Started ifup for eth0. Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting Create Volatile Files and Directories... Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Created slice system-bthelper.slice. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started ifup for wlan0. Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting Load/Save RF Kill Switch Status... Aug 29 19:51:09 donquixotevolumio systemd[1]: nfs-config.service: Succeeded. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Preprocess NFS configuration. Aug 29 19:51:09 donquixotevolumio systemd[1]: plymouth-read-write.service: Succeeded. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Aug 29 19:51:09 donquixotevolumio systemd[1]: Received SIGRTMIN+20 from PID 205 (plymouthd). Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Reached target NFS client services. Aug 29 19:51:09 donquixotevolumio systemd[1]: plymouth-start.service: Succeeded. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Show Plymouth Boot Screen. Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Load/Save RF Kill Switch Status. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Create Volatile Files and Directories. Aug 29 19:51:09 donquixotevolumio kernel: Bluetooth: hci0: BCM: features 0x2f Aug 29 19:51:09 donquixotevolumio kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Aug 29 19:51:09 donquixotevolumio kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting RPC bind portmap service... Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting Update UTMP about System Boot/Shutdown... Aug 29 19:51:09 donquixotevolumio kernel: 8021q: 802.1Q VLAN Support v1.8 Aug 29 19:51:09 donquixotevolumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Update UTMP about System Boot/Shutdown. Aug 29 19:51:09 donquixotevolumio systemd[1]: Reached target System Initialization. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Daily apt download activities. Aug 29 19:51:09 donquixotevolumio systemd[1]: Listening on D-Bus System Message Bus Socket. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Daily apt upgrade and clean activities. Aug 29 19:51:09 donquixotevolumio systemd[1]: Listening on triggerhappy.socket. Aug 29 19:51:09 donquixotevolumio systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Aug 29 19:51:09 donquixotevolumio systemd[1]: Reached target Sockets. Aug 29 19:51:09 donquixotevolumio systemd[1]: Reached target Basic System. Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Manage Sound Card State (restore and store). Aug 29 19:51:09 donquixotevolumio alsactl[632]: alsactl 1.1.8 daemon started Aug 29 19:51:09 donquixotevolumio systemd[1]: Started Volumio Log Rotation Service. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started UPnP Renderer front-end to MPD. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started volumio-remote-updater.service. Aug 29 19:51:09 donquixotevolumio systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Aug 29 19:51:09 donquixotevolumio systemd[1]: Started D-Bus System Message Bus. Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting Wireless Services... Aug 29 19:51:09 donquixotevolumio systemd[1]: Starting dhcpcd on all interfaces... Aug 29 19:51:10 donquixotevolumio avahi-daemon[617]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Aug 29 19:51:10 donquixotevolumio avahi-daemon[617]: Successfully dropped root privileges. Aug 29 19:51:10 donquixotevolumio systemd[1]: Starting triggerhappy global hotkey daemon... Aug 29 19:51:10 donquixotevolumio avahi-daemon[617]: avahi-daemon 0.7 starting up. Aug 29 19:51:10 donquixotevolumio systemd[1]: Starting Login Service... Aug 29 19:51:10 donquixotevolumio systemd[1]: Starting Configure Bluetooth Modems connected by UART... Aug 29 19:51:10 donquixotevolumio systemd[1]: Starting WPA supplicant... Aug 29 19:51:10 donquixotevolumio dhcpcd[644]: Not running dhcpcd because /etc/network/interfaces Aug 29 19:51:10 donquixotevolumio dhcpcd[644]: defines some interfaces that will use a Aug 29 19:51:10 donquixotevolumio dhcpcd[644]: DHCP client or static address Aug 29 19:51:10 donquixotevolumio systemd[1]: Starting Save/Restore Sound Card State... Aug 29 19:51:10 donquixotevolumio systemd[1]: Started Volumio Iptables Module. Aug 29 19:51:10 donquixotevolumio systemd[1]: Started Daily Cleanup of Temporary Directories. Aug 29 19:51:10 donquixotevolumio systemd[1]: Reached target Timers. Aug 29 19:51:10 donquixotevolumio systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Aug 29 19:51:10 donquixotevolumio systemd[1]: Started RPC bind portmap service. Aug 29 19:51:10 donquixotevolumio systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Aug 29 19:51:10 donquixotevolumio systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Aug 29 19:51:10 donquixotevolumio systemd[1]: Failed to start dhcpcd on all interfaces. Aug 29 19:51:10 donquixotevolumio sh[533]: eth0: waiting for carrier Aug 29 19:51:10 donquixotevolumio dhcpcd[580]: eth0: waiting for carrier Aug 29 19:51:10 donquixotevolumio kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Aug 29 19:51:10 donquixotevolumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Aug 29 19:51:10 donquixotevolumio systemd[1]: Reached target RPC Port Mapper. Aug 29 19:51:10 donquixotevolumio systemd[1]: Reached target Remote File Systems (Pre). Aug 29 19:51:10 donquixotevolumio systemd[1]: Reached target Remote File Systems. Aug 29 19:51:10 donquixotevolumio thd[647]: Unable to parse trigger line: Aug 29 19:51:10 donquixotevolumio thd[647]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Aug 29 19:51:10 donquixotevolumio thd[647]: Unable to parse trigger line: Aug 29 19:51:10 donquixotevolumio thd[647]: Found socket passed from systemd Aug 29 19:51:10 donquixotevolumio sh[537]: wlan0=wlan0 Aug 29 19:51:10 donquixotevolumio systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Aug 29 19:51:10 donquixotevolumio systemd[1]: Started triggerhappy global hotkey daemon. Aug 29 19:51:10 donquixotevolumio systemd[1]: Started Save/Restore Sound Card State. Aug 29 19:51:10 donquixotevolumio systemd[1]: Reached target Sound Card. Aug 29 19:51:10 donquixotevolumio systemd-logind[652]: New seat seat0. Aug 29 19:51:10 donquixotevolumio systemd[1]: hciuart.service: Succeeded. Aug 29 19:51:10 donquixotevolumio systemd[1]: Started Configure Bluetooth Modems connected by UART. Aug 29 19:51:10 donquixotevolumio avahi-daemon[617]: Successfully called chroot(). Aug 29 19:51:10 donquixotevolumio avahi-daemon[617]: Successfully dropped remaining capabilities. Aug 29 19:51:10 donquixotevolumio wpa_supplicant[655]: Successfully initialized wpa_supplicant Aug 29 19:51:10 donquixotevolumio avahi-daemon[617]: Loading service file /services/volumio.service. Aug 29 19:51:10 donquixotevolumio avahi-daemon[617]: Network interface enumeration completed. Aug 29 19:51:10 donquixotevolumio avahi-daemon[617]: Server startup complete. Host name is donquixotevolumio.local. Local service cookie is 3264383530. Aug 29 19:51:10 donquixotevolumio avahi-daemon[617]: Service "DonQuixoteVolumio" (/services/volumio.service) successfully established. Aug 29 19:51:10 donquixotevolumio systemd[1]: Started Raise network interfaces. Aug 29 19:51:10 donquixotevolumio systemd[1]: Started Login Service. Aug 29 19:51:10 donquixotevolumio systemd[1]: Started Avahi mDNS/DNS-SD Stack. Aug 29 19:51:10 donquixotevolumio systemd[1]: Started WPA supplicant. Aug 29 19:51:10 donquixotevolumio systemd[1]: Reached target Network. Aug 29 19:51:10 donquixotevolumio systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Aug 29 19:51:10 donquixotevolumio systemd[1]: Reached target Network is Online. Aug 29 19:51:11 donquixotevolumio systemd[1]: Starting LSB: Brings up/down network automatically... Aug 29 19:51:11 donquixotevolumio systemd[1]: Starting /etc/rc.local Compatibility... Aug 29 19:51:11 donquixotevolumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 29 19:51:11 donquixotevolumio systemd[1]: Starting Samba NMB Daemon... Aug 29 19:51:11 donquixotevolumio systemd[1]: Starting Permit User Sessions... Aug 29 19:51:11 donquixotevolumio systemd[1]: Starting Network Time Service... Aug 29 19:51:11 donquixotevolumio systemd[1]: Starting Raspberry Pi bluetooth helper... Aug 29 19:51:11 donquixotevolumio systemd[1]: Started /etc/rc.local Compatibility. Aug 29 19:51:11 donquixotevolumio systemd[1]: Started Permit User Sessions. Aug 29 19:51:11 donquixotevolumio volumio-remote-updater[637]: Error: No active session Aug 29 19:51:11 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:11] [info] asio async_connect error: system:111 (Connection refused) Aug 29 19:51:11 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:11] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Aug 29 19:51:11 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:11] [error] handle_connect error: Underlying Transport Error Aug 29 19:51:11 donquixotevolumio systemd[1]: Starting Hold until boot process finishes up... Aug 29 19:51:11 donquixotevolumio systemd[1]: Starting Terminate Plymouth Boot Screen... Aug 29 19:51:11 donquixotevolumio bthelper[719]: Raspberry Pi BDADDR already set Aug 29 19:51:11 donquixotevolumio systemd[1]: Started Raspberry Pi bluetooth helper. Aug 29 19:51:11 donquixotevolumio volumio[636]: Could not open config: /tmp/upmpdcli.conf Aug 29 19:51:11 donquixotevolumio systemd[1]: Received SIGRTMIN+21 from PID 205 (plymouthd). Aug 29 19:51:11 donquixotevolumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 19:51:11 donquixotevolumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 19:51:11 donquixotevolumio systemd[1]: Starting Bluetooth service... Aug 29 19:51:11 donquixotevolumio ifplugd(eth0)[771]: ifplugd 0.28 initializing. Aug 29 19:51:11 donquixotevolumio systemd[1]: Received SIGRTMIN+21 from PID 205 (plymouthd). Aug 29 19:51:11 donquixotevolumio ifplugd(eth0)[771]: Using interface eth0/D8:3A:DD:63:F8:26 with driver (version: 6.1.77-v7l+) Aug 29 19:51:11 donquixotevolumio ifplugd(eth0)[771]: Using detection mode: SIOCETHTOOL Aug 29 19:51:11 donquixotevolumio ifplugd(eth0)[771]: Initialization complete, link beat not detected. Aug 29 19:51:11 donquixotevolumio systemd[1]: plymouth-quit.service: Succeeded. Aug 29 19:51:11 donquixotevolumio systemd[1]: Started Terminate Plymouth Boot Screen. Aug 29 19:51:11 donquixotevolumio systemd[1]: plymouth-quit-wait.service: Succeeded. Aug 29 19:51:11 donquixotevolumio systemd[1]: Started Hold until boot process finishes up. Aug 29 19:51:11 donquixotevolumio loadcpufreq[667]: Loading cpufreq kernel modules...done (none). Aug 29 19:51:11 donquixotevolumio ntpd[717]: ntpd 4.2.8p12@1.3728-o (1): Starting Aug 29 19:51:11 donquixotevolumio systemd[1]: Started Getty on tty1. Aug 29 19:51:11 donquixotevolumio ifplugd[706]: Network Interface Plugging Daemon...start eth0...done. Aug 29 19:51:11 donquixotevolumio ntpd[717]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Aug 29 19:51:11 donquixotevolumio systemd[1]: Reached target Login Prompts. Aug 29 19:51:11 donquixotevolumio systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Aug 29 19:51:11 donquixotevolumio systemd[1]: Started LSB: Brings up/down network automatically. Aug 29 19:51:11 donquixotevolumio systemd[1]: Started Network Time Service. Aug 29 19:51:11 donquixotevolumio systemd[1]: Starting LSB: set CPUFreq kernel parameters... Aug 29 19:51:11 donquixotevolumio ntpd[778]: proto: precision = 2.093 usec (-19) Aug 29 19:51:11 donquixotevolumio ntpd[778]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Aug 29 19:51:11 donquixotevolumio ntpd[778]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Aug 29 19:51:11 donquixotevolumio ntpd[778]: Listen and drop on 0 v6wildcard [::]:123 Aug 29 19:51:11 donquixotevolumio ntpd[778]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Aug 29 19:51:11 donquixotevolumio ntpd[778]: Listen normally on 2 lo 127.0.0.1:123 Aug 29 19:51:11 donquixotevolumio ntpd[778]: Listening on routing socket on fd #19 for interface updates Aug 29 19:51:11 donquixotevolumio ntpd[778]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Aug 29 19:51:11 donquixotevolumio ntpd[778]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Aug 29 19:51:11 donquixotevolumio systemd[1]: iptables.service: Succeeded. Aug 29 19:51:11 donquixotevolumio bluetoothd[762]: Bluetooth daemon 5.50 Aug 29 19:51:11 donquixotevolumio bluetoothd[762]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Aug 29 19:51:11 donquixotevolumio systemd[1]: Started Bluetooth service. Aug 29 19:51:11 donquixotevolumio systemd[1]: Reached target Bluetooth. Aug 29 19:51:11 donquixotevolumio bluetoothd[762]: Starting SDP server Aug 29 19:51:11 donquixotevolumio bluetoothd[762]: Excluding (cli) sap Aug 29 19:51:12 donquixotevolumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Aug 29 19:51:12 donquixotevolumio kernel: Bluetooth: BNEP filters: protocol multicast Aug 29 19:51:12 donquixotevolumio kernel: Bluetooth: BNEP socket layer initialized Aug 29 19:51:12 donquixotevolumio bluetoothd[762]: Bluetooth management interface 1.22 initialized Aug 29 19:51:12 donquixotevolumio dbus-daemon[640]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=762 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Aug 29 19:51:12 donquixotevolumio kernel: Bluetooth: MGMT ver 1.22 Aug 29 19:51:12 donquixotevolumio cpufrequtils[780]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Aug 29 19:51:12 donquixotevolumio systemd[1]: Started LSB: set CPUFreq kernel parameters. Aug 29 19:51:12 donquixotevolumio bluetoothd[762]: Failed to set privacy: Rejected (0x0b) Aug 29 19:51:12 donquixotevolumio systemd[1]: Starting Hostname Service... Aug 29 19:51:12 donquixotevolumio dbus-daemon[640]: [system] Successfully activated service 'org.freedesktop.hostname1' Aug 29 19:51:12 donquixotevolumio systemd[1]: Started Hostname Service. Aug 29 19:51:12 donquixotevolumio nmbd[721]: [2024/08/29 19:51:12.459570, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Aug 29 19:51:12 donquixotevolumio nmbd[721]: started asyncdns process 805 Aug 29 19:51:12 donquixotevolumio nmbd[721]: [2024/08/29 19:51:12.462175, 0] ../lib/util/become_daemon.c:149(daemon_status) Aug 29 19:51:12 donquixotevolumio nmbd[721]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Aug 29 19:51:12 donquixotevolumio nmbd[721]: [2024/08/29 19:51:12.462610, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Aug 29 19:51:12 donquixotevolumio nmbd[721]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Aug 29 19:51:12 donquixotevolumio haveged[581]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Aug 29 19:51:12 donquixotevolumio haveged[581]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Aug 29 19:51:12 donquixotevolumio haveged[581]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99883 Aug 29 19:51:12 donquixotevolumio haveged[581]: haveged: fills: 0, generated: 0 Aug 29 19:51:12 donquixotevolumio ntpd[778]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Aug 29 19:51:12 donquixotevolumio wireless.js[643]: Cleaning previous... Aug 29 19:51:12 donquixotevolumio sudo[813]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 29 19:51:12 donquixotevolumio sudo[813]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:12 donquixotevolumio sudo[813]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:12 donquixotevolumio sudo[815]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 29 19:51:12 donquixotevolumio sudo[815]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:13 donquixotevolumio sudo[815]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:13 donquixotevolumio wireless.js[643]: Stopped aP Aug 29 19:51:13 donquixotevolumio sudo[822]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 29 19:51:13 donquixotevolumio sudo[822]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:13 donquixotevolumio sudo[822]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:13 donquixotevolumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 29 19:51:13 donquixotevolumio sudo[824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Aug 29 19:51:13 donquixotevolumio sudo[824]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:13 donquixotevolumio sudo[824]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:13 donquixotevolumio sudo[831]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 29 19:51:13 donquixotevolumio sudo[831]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:13 donquixotevolumio sudo[831]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:13 donquixotevolumio sudo[833]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Aug 29 19:51:13 donquixotevolumio sudo[833]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:13 donquixotevolumio ntpd[778]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Aug 29 19:51:14 donquixotevolumio sh[533]: eth0: carrier acquired Aug 29 19:51:14 donquixotevolumio dhcpcd[580]: eth0: carrier acquired Aug 29 19:51:14 donquixotevolumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Aug 29 19:51:14 donquixotevolumio sh[533]: DUID 00:01:00:01:2d:bb:b4:91:d8:3a:dd:63:f8:26 Aug 29 19:51:14 donquixotevolumio sh[533]: eth0: IAID dd:63:f8:26 Aug 29 19:51:14 donquixotevolumio dhcpcd[580]: DUID 00:01:00:01:2d:bb:b4:91:d8:3a:dd:63:f8:26 Aug 29 19:51:14 donquixotevolumio dhcpcd[580]: eth0: IAID dd:63:f8:26 Aug 29 19:51:14 donquixotevolumio sh[533]: eth0: adding address fe80::e246:ff61:70aa:8de Aug 29 19:51:14 donquixotevolumio sh[533]: ipv6_addaddr1: Permission denied Aug 29 19:51:14 donquixotevolumio dhcpcd[580]: eth0: adding address fe80::e246:ff61:70aa:8de Aug 29 19:51:14 donquixotevolumio dhcpcd[580]: ipv6_addaddr1: Permission denied Aug 29 19:51:14 donquixotevolumio systemd[1]: systemd-rfkill.service: Succeeded. Aug 29 19:51:14 donquixotevolumio sh[533]: eth0: rebinding lease of 192.168.68.68 Aug 29 19:51:14 donquixotevolumio dhcpcd[580]: eth0: rebinding lease of 192.168.68.68 Aug 29 19:51:14 donquixotevolumio sh[533]: eth0: probing address 192.168.68.68/22 Aug 29 19:51:14 donquixotevolumio dhcpcd[580]: eth0: probing address 192.168.68.68/22 Aug 29 19:51:14 donquixotevolumio ifplugd(eth0)[771]: Link beat detected. Aug 29 19:51:14 donquixotevolumio ntpd[778]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Aug 29 19:51:14 donquixotevolumio ifplugd(eth0)[771]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Aug 29 19:51:14 donquixotevolumio ifplugd(eth0)[771]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Aug 29 19:51:15 donquixotevolumio sh[533]: eth0: soliciting an IPv6 router Aug 29 19:51:15 donquixotevolumio dhcpcd[580]: eth0: soliciting an IPv6 router Aug 29 19:51:15 donquixotevolumio ntpd[778]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Aug 29 19:51:16 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:16] [info] asio async_connect error: system:111 (Connection refused) Aug 29 19:51:16 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:16] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Aug 29 19:51:16 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:16] [error] handle_connect error: Underlying Transport Error Aug 29 19:51:16 donquixotevolumio sudo[833]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:16 donquixotevolumio wireless.js[643]: SETTING APPROPRIATE REG DOMAIN: US Aug 29 19:51:16 donquixotevolumio sudo[845]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 29 19:51:16 donquixotevolumio sudo[845]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:16 donquixotevolumio sudo[845]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:16 donquixotevolumio sudo[847]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set US Aug 29 19:51:16 donquixotevolumio sudo[847]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:16 donquixotevolumio sudo[847]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:16 donquixotevolumio wireless.js[643]: SUCCESSFULLY SET NEW REGDOMAIN: US Aug 29 19:51:16 donquixotevolumio wireless.js[643]: Start wireless flow Aug 29 19:51:16 donquixotevolumio wireless.js[643]: Stopped hotspot (if there).. Aug 29 19:51:16 donquixotevolumio sudo[852]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 29 19:51:16 donquixotevolumio sudo[852]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:16 donquixotevolumio sudo[852]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:16 donquixotevolumio sudo[854]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 29 19:51:16 donquixotevolumio sudo[854]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:16 donquixotevolumio bthelper[719]: Changing power off succeeded Aug 29 19:51:16 donquixotevolumio bthelper[719]: [CHG] Controller D8:3A:DD:63:F8:2B Class: 0x0000041c Aug 29 19:51:16 donquixotevolumio bthelper[719]: Changing power on succeeded Aug 29 19:51:17 donquixotevolumio sudo[854]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:17 donquixotevolumio wireless.js[643]: DHCP IP Aug 29 19:51:17 donquixotevolumio wireless.js[643]: Start ap Aug 29 19:51:17 donquixotevolumio wpa_supplicant[863]: Successfully initialized wpa_supplicant Aug 29 19:51:17 donquixotevolumio sudo[864]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Aug 29 19:51:17 donquixotevolumio sudo[864]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:17 donquixotevolumio dhcpcd[865]: dev: loaded udev Aug 29 19:51:17 donquixotevolumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 29 19:51:17 donquixotevolumio dhcpcd-run-hooks[874]: wlan0: starting wpa_supplicant Aug 29 19:51:17 donquixotevolumio dhcpcd-run-hooks[879]: wlan0: failed to start wpa_supplicant Aug 29 19:51:17 donquixotevolumio dhcpcd-run-hooks[880]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Aug 29 19:51:17 donquixotevolumio dhcpcd[865]: wlan0: connected to Access Point `' Aug 29 19:51:17 donquixotevolumio dhcpcd[865]: DUID 00:01:00:01:2d:bb:b4:91:d8:3a:dd:63:f8:26 Aug 29 19:51:17 donquixotevolumio dhcpcd[865]: eth0: IAID dd:63:f8:26 Aug 29 19:51:17 donquixotevolumio dhcpcd[865]: eth0: adding address fe80::e246:ff61:70aa:8de Aug 29 19:51:17 donquixotevolumio dhcpcd[865]: ipv6_addaddr1: Permission denied Aug 29 19:51:17 donquixotevolumio dhcpcd[865]: wlan0: waiting for carrier Aug 29 19:51:17 donquixotevolumio dhcpcd[865]: eth0: rebinding lease of 192.168.68.68 Aug 29 19:51:17 donquixotevolumio dhcpcd[865]: eth0: probing address 192.168.68.68/22 Aug 29 19:51:17 donquixotevolumio dhcpcd[865]: eth0: soliciting an IPv6 router Aug 29 19:51:18 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:18 donquixotevolumio sudo[891]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:18 donquixotevolumio sudo[891]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:18 donquixotevolumio sudo[891]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:19 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:19 donquixotevolumio sudo[894]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:19 donquixotevolumio sudo[894]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:19 donquixotevolumio sudo[894]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:19 donquixotevolumio sh[533]: eth0: leased 192.168.68.68 for 7200 seconds Aug 29 19:51:19 donquixotevolumio sh[533]: eth0: adding route to 192.168.68.0/22 Aug 29 19:51:19 donquixotevolumio sh[533]: eth0: adding default route via 192.168.68.1 Aug 29 19:51:19 donquixotevolumio dhcpcd[580]: eth0: leased 192.168.68.68 for 7200 seconds Aug 29 19:51:19 donquixotevolumio dhcpcd[580]: eth0: adding route to 192.168.68.0/22 Aug 29 19:51:19 donquixotevolumio avahi-daemon[617]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.68.68. Aug 29 19:51:19 donquixotevolumio avahi-daemon[617]: New relevant interface eth0.IPv4 for mDNS. Aug 29 19:51:19 donquixotevolumio dhcpcd[580]: eth0: adding default route via 192.168.68.1 Aug 29 19:51:19 donquixotevolumio avahi-daemon[617]: Registering new address record for 192.168.68.68 on eth0.IPv4. Aug 29 19:51:19 donquixotevolumio sh[533]: forked to background, child pid 916 Aug 29 19:51:19 donquixotevolumio dhcpcd[580]: forked to background, child pid 916 Aug 29 19:51:19 donquixotevolumio ifplugd(eth0)[771]: client: ifup: interface eth0 already configured Aug 29 19:51:19 donquixotevolumio sh[533]: eth0=eth0 Aug 29 19:51:19 donquixotevolumio ifplugd(eth0)[771]: Program executed successfully. Aug 29 19:51:20 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:20 donquixotevolumio wpa_supplicant[878]: wlan0: Trying to associate with SSID 'AccurexMax' Aug 29 19:51:20 donquixotevolumio sudo[943]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:20 donquixotevolumio sudo[943]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:20 donquixotevolumio sudo[943]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:21 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:21 donquixotevolumio sudo[946]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:21 donquixotevolumio sudo[946]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:21 donquixotevolumio sudo[946]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:21 donquixotevolumio ntpd[778]: Listen normally on 3 eth0 192.168.68.68:123 Aug 29 19:51:21 donquixotevolumio ntpd[778]: new interface(s) found: waking up resolver Aug 29 19:51:22 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:22 donquixotevolumio sudo[949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:22 donquixotevolumio sudo[949]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:22 donquixotevolumio sudo[949]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:22 donquixotevolumio systemd[1]: Started Samba NMB Daemon. Aug 29 19:51:22 donquixotevolumio nmbd[721]: [2024/08/29 19:51:22.471250, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 29 19:51:22 donquixotevolumio nmbd[721]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Aug 29 19:51:22 donquixotevolumio systemd[1]: Starting Samba Winbind Daemon... Aug 29 19:51:22 donquixotevolumio dhcpcd[865]: eth0: leased 192.168.68.68 for 7200 seconds Aug 29 19:51:22 donquixotevolumio dhcpcd[865]: eth0: adding route to 192.168.68.0/22 Aug 29 19:51:22 donquixotevolumio dhcpcd[865]: eth0: adding default route via 192.168.68.1 Aug 29 19:51:22 donquixotevolumio dhcpcd[865]: forked to background, child pid 973 Aug 29 19:51:22 donquixotevolumio sudo[864]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:22 donquixotevolumio winbindd[951]: [2024/08/29 19:51:22.749984, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Aug 29 19:51:22 donquixotevolumio winbindd[951]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Aug 29 19:51:22 donquixotevolumio winbindd[951]: [2024/08/29 19:51:22.767366, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 29 19:51:22 donquixotevolumio systemd[1]: Started Samba Winbind Daemon. Aug 29 19:51:22 donquixotevolumio winbindd[951]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Aug 29 19:51:22 donquixotevolumio systemd[1]: Starting Samba SMB Daemon... Aug 29 19:51:22 donquixotevolumio dhcpcd[973]: wlan0: carrier acquired Aug 29 19:51:22 donquixotevolumio wpa_supplicant[878]: wlan0: Associated with 52:af:97:50:bc:f9 Aug 29 19:51:22 donquixotevolumio wpa_supplicant[878]: wlan0: CTRL-EVENT-CONNECTED - Connection to 52:af:97:50:bc:f9 completed [id=0 id_str=] Aug 29 19:51:22 donquixotevolumio dhcpcd[973]: wlan0: connected to Access Point `AccurexMax' Aug 29 19:51:22 donquixotevolumio wpa_supplicant[878]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 29 19:51:22 donquixotevolumio wpa_supplicant[878]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Aug 29 19:51:22 donquixotevolumio dhcpcd[973]: wlan0: IAID dd:63:f8:29 Aug 29 19:51:22 donquixotevolumio dhcpcd[973]: wlan0: adding address fe80::8db4:e95d:5419:eced Aug 29 19:51:22 donquixotevolumio dhcpcd[973]: ipv6_addaddr1: Permission denied Aug 29 19:51:22 donquixotevolumio dhcpcd[973]: wlan0: carrier lost Aug 29 19:51:23 donquixotevolumio dhcpcd[973]: wlan0: carrier acquired Aug 29 19:51:23 donquixotevolumio dhcpcd[973]: wlan0: IAID dd:63:f8:29 Aug 29 19:51:23 donquixotevolumio dhcpcd[973]: wlan0: rebinding lease of 192.168.68.69 Aug 29 19:51:23 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:23 donquixotevolumio dhcpcd[973]: wlan0: soliciting an IPv6 router Aug 29 19:51:23 donquixotevolumio sudo[999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:23 donquixotevolumio sudo[999]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:23 donquixotevolumio sudo[999]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:23 donquixotevolumio dhcpcd[973]: wlan0: probing address 192.168.68.69/22 Aug 29 19:51:23 donquixotevolumio smbd[977]: [2024/08/29 19:51:23.216876, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 29 19:51:23 donquixotevolumio smbd[977]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Aug 29 19:51:23 donquixotevolumio systemd[1]: Started Samba SMB Daemon. Aug 29 19:51:23 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:23] [info] asio async_connect error: system:111 (Connection refused) Aug 29 19:51:23 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:23] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Aug 29 19:51:23 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:23] [error] handle_connect error: Underlying Transport Error Aug 29 19:51:24 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:24 donquixotevolumio sudo[1008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:24 donquixotevolumio sudo[1008]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:24 donquixotevolumio sudo[1008]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:25 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:25 donquixotevolumio sudo[1011]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:25 donquixotevolumio sudo[1011]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:25 donquixotevolumio sudo[1011]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:26 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:26 donquixotevolumio sudo[1014]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:26 donquixotevolumio sudo[1014]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:26 donquixotevolumio sudo[1014]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:27 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:27 donquixotevolumio sudo[1017]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:27 donquixotevolumio sudo[1017]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:27 donquixotevolumio sudo[1017]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:28 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:28 donquixotevolumio sudo[1020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:28 donquixotevolumio sudo[1020]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:28 donquixotevolumio sudo[1020]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:28 donquixotevolumio dhcpcd[973]: wlan0: leased 192.168.68.69 for 7200 seconds Aug 29 19:51:28 donquixotevolumio avahi-daemon[617]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.69. Aug 29 19:51:28 donquixotevolumio dhcpcd[973]: wlan0: adding route to 192.168.68.0/22 Aug 29 19:51:28 donquixotevolumio avahi-daemon[617]: New relevant interface wlan0.IPv4 for mDNS. Aug 29 19:51:28 donquixotevolumio dhcpcd[973]: wlan0: adding default route via 192.168.68.1 Aug 29 19:51:28 donquixotevolumio avahi-daemon[617]: Registering new address record for 192.168.68.69 on wlan0.IPv4. Aug 29 19:51:29 donquixotevolumio wireless.js[643]: trying... Aug 29 19:51:29 donquixotevolumio sudo[1043]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 29 19:51:29 donquixotevolumio sudo[1043]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:29 donquixotevolumio sudo[1043]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:29 donquixotevolumio wireless.js[643]: Connected to: ----AccurexMax Aug 29 19:51:29 donquixotevolumio wireless.js[643]: ---- Aug 29 19:51:29 donquixotevolumio sudo[1046]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 19:51:29 donquixotevolumio sudo[1046]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:29 donquixotevolumio sudo[1046]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:29 donquixotevolumio wireless.js[643]: ... joined AP, wlan0 IPv4 is 192.168.68.69, ipV6 is undefined Aug 29 19:51:29 donquixotevolumio wireless.js[643]: It's done! AP Aug 29 19:51:29 donquixotevolumio systemd[1]: Started Wireless Services. Aug 29 19:51:29 donquixotevolumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 29 19:51:29 donquixotevolumio systemd[1]: Started Volumio Backend Module. Aug 29 19:51:29 donquixotevolumio systemd[1]: Started Volumio Cpu Tweaker. Aug 29 19:51:29 donquixotevolumio systemd[1]: Reached target Multi-User System. Aug 29 19:51:29 donquixotevolumio systemd[1]: Reached target Graphical Interface. Aug 29 19:51:29 donquixotevolumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Aug 29 19:51:29 donquixotevolumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Aug 29 19:51:29 donquixotevolumio systemd[1]: Started Update UTMP about System Runlevel Changes. Aug 29 19:51:29 donquixotevolumio systemd[1]: Startup finished in 14.183s (kernel) + 25.492s (userspace) = 39.675s. Aug 29 19:51:29 donquixotevolumio volumio-cpu-tweak[1052]: Setting RT Priority for mpd Aug 29 19:51:29 donquixotevolumio volumio-cpu-tweak[1052]: pid 35's current scheduling policy: SCHED_OTHER Aug 29 19:51:29 donquixotevolumio volumio-cpu-tweak[1052]: pid 35's current scheduling priority: 0 Aug 29 19:51:29 donquixotevolumio volumio-cpu-tweak[1052]: Setting MPD Affinity Aug 29 19:51:29 donquixotevolumio volumio-cpu-tweak[1052]: pid 3's current affinity mask: f Aug 29 19:51:29 donquixotevolumio volumio-cpu-tweak[1052]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Aug 29 19:51:29 donquixotevolumio volumio-cpu-tweak[1052]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Aug 29 19:51:29 donquixotevolumio systemd[1]: volumio_cpu_tweak.service: Succeeded. Aug 29 19:51:30 donquixotevolumio ntpd[778]: Listen normally on 4 wlan0 192.168.68.69:123 Aug 29 19:51:30 donquixotevolumio ntpd[778]: new interface(s) found: waking up resolver Aug 29 19:51:30 donquixotevolumio volumio[1051]: info: ------------------------------------------- Aug 29 19:51:30 donquixotevolumio volumio[1051]: info: ----- Volumio3 ---- Aug 29 19:51:30 donquixotevolumio volumio[1051]: info: ------------------------------------------- Aug 29 19:51:30 donquixotevolumio volumio[1051]: info: ----- System startup ---- Aug 29 19:51:30 donquixotevolumio volumio[1051]: info: ------------------------------------------- Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: MYVOLUMIO Environment detected Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Plugin folders cleanup Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Scanning into folder /volumio/app/plugins/ Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Scanning category audio_interface Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Scanning category miscellanea Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Scanning category music_service Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Scanning category plugins.json Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Scanning category system_controller Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Scanning category user_interface Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Scanning into folder /data/plugins/ Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Scanning category music_service Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Plugin folders cleanup completed Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: ------------------------------------------- Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: ----- Core plugins startup ---- Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: ------------------------------------------- Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Loading plugins from folder /volumio/app/plugins/ Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Adding plugin upnp to MyMusic Plugins Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Loading plugins from folder /data/plugins/ Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Loading plugin "system"... Aug 29 19:51:31 donquixotevolumio volumio[1051]: info: Loading plugin "appearance"... Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Loading plugin "network"... Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Refreshing Cached IP Addresses Aug 29 19:51:32 donquixotevolumio sudo[1083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 19:51:32 donquixotevolumio sudo[1083]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:32 donquixotevolumio sudo[1083]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Loading plugin "services"... Aug 29 19:51:32 donquixotevolumio sudo[1085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 19:51:32 donquixotevolumio sudo[1085]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Loading plugin "alsa_controller"... Aug 29 19:51:32 donquixotevolumio sudo[1085]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:32 donquixotevolumio sudo[1088]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 29 19:51:32 donquixotevolumio sudo[1088]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Loading plugin "wizard"... Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Loading plugin "networkfs"... Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Starting Udev Watcher for removable devices Aug 29 19:51:32 donquixotevolumio sudo[1094]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=admin,password=@Donquixote01#,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.2.48/Multimedia/Music /mnt/NAS/DonQuixoteNAS Aug 29 19:51:32 donquixotevolumio sudo[1094]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Ignoring mount for partition: boot Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Ignoring mount for partition: volumio Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Ignoring mount for partition: volumio_data Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Loading plugin "volumio_command_line_client"... Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Loading plugin "upnp"... Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: [1724986292914] Starting Upmpd Daemon Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Loading plugin "my_music"... Aug 29 19:51:32 donquixotevolumio volumio[1051]: info: Loading plugin "mpd"... Aug 29 19:51:33 donquixotevolumio kernel: Key type cifs.spnego registered Aug 29 19:51:33 donquixotevolumio kernel: Key type cifs.idmap registered Aug 29 19:51:33 donquixotevolumio 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. Aug 29 19:51:33 donquixotevolumio kernel: CIFS: Attempting to mount \\192.168.2.48\Multimedia Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Loading plugin "upnp_browser"... Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Loading plugin "alarm-clock"... Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Loading plugin "airplay_emulation"... Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Starting Shairport Sync Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Loading plugin "last_100"... Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Loading plugin "webradio"... Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Loading plugin "i2s_dacs"... Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Loading plugin "volumiodiscovery"... Aug 29 19:51:33 donquixotevolumio sudo[1094]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:33 donquixotevolumio volumio[1051]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 19:51:33 donquixotevolumio node[1051]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 19:51:33 donquixotevolumio volumio[1051]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 19:51:33 donquixotevolumio node[1051]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 19:51:33 donquixotevolumio volumio[1051]: *** WARNING *** For more information see Aug 29 19:51:33 donquixotevolumio node[1051]: *** WARNING *** For more information see Aug 29 19:51:33 donquixotevolumio volumio[1051]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 19:51:33 donquixotevolumio node[1051]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 19:51:33 donquixotevolumio volumio[1051]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 19:51:33 donquixotevolumio node[1051]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 19:51:33 donquixotevolumio volumio[1051]: *** WARNING *** For more information see Aug 29 19:51:33 donquixotevolumio node[1051]: *** WARNING *** For more information see Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Discovery: Started advertising with name: DonQuixoteVolumio Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 19:51:33 donquixotevolumio volumio[1051]: info: Loading plugin "spop"... Aug 29 19:51:33 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:33] [connect] Successful connection Aug 29 19:51:34 donquixotevolumio volumio[1051]: info: Loading plugin "youtube2"... Aug 29 19:51:35 donquixotevolumio volumio[1051]: info: Loading plugin "ytcr"... Aug 29 19:51:36 donquixotevolumio sudo[1088]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: Loading plugin "outputs"... Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: Loading plugin "albumart"... Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: Plugin example_plugin is not enabled Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: Loading plugin "inputs"... Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: Loading plugin "updater_comm"... Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: Plugin mpdemulation is not enabled Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: Loading plugin "rest_api"... Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: Loading plugin "websocket"... Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: Starting Socket.io Server version 2.3.0 Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: Loading i18n strings for locale en Aug 29 19:51:37 donquixotevolumio volumio[1051]: Updating browse sources language Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 19:51:37 donquixotevolumio volumio[1051]: Forking 3 albumart workers Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::initPlayerControls Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 19:51:37 donquixotevolumio volumio[1051]: Express server listening on port 3000 Aug 29 19:51:37 donquixotevolumio volumio[1051]: [Metrics] WebUI: 7s 527.07ms Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreStateMachine::resetVolumioState Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreStateMachine::getcurrentVolume Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreStateMachine::pushState Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 19:51:37 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioPushState Aug 29 19:51:38 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Aug 29 19:51:38 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Aug 29 19:51:38 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.68 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Aug 29 19:51:38 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Aug 29 19:51:38 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.68 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Aug 29 19:51:38 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.68 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Aug 29 19:51:38 donquixotevolumio volumio-remote-updater[637]: [2024-08-29 19:51:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1724986293 101 Aug 29 19:51:38 donquixotevolumio volumio[1051]: 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: 7 Aug 29 19:51:38 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.68 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Aug 29 19:51:38 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.68 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Reloading queue from file Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreStateMachine::setRepeat null single undefined Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreStateMachine::pushState Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioPushState Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreStateMachine::setRandom null Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreStateMachine::pushState Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioPushState Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 29 19:51:38 donquixotevolumio volumio[1051]: Starting albumart workers Aug 29 19:51:38 donquixotevolumio volumio[1051]: Starting albumart workers Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Setting Device type: Raspberry PI Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Completed loading Core Plugins Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Preparing to generate the ALSA configuration file Aug 29 19:51:38 donquixotevolumio volumio[1051]: Starting albumart workers Aug 29 19:51:38 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Asound.conf file unchanged, so no further update is needed Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Output device has changed, restarting MPD Aug 29 19:51:38 donquixotevolumio sudo[1159]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 19:51:38 donquixotevolumio sudo[1159]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:38 donquixotevolumio sudo[1159]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Output device has changed, restarting Shairport Sync Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 19:51:38 donquixotevolumio sudo[1162]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 19:51:38 donquixotevolumio sudo[1162]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: ___________ START PLUGINS ___________ Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: ControllerMpd::onStart: Initializing MPD Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Creating MPD Configuration file Aug 29 19:51:38 donquixotevolumio systemd[1]: Listening on mpd.socket. Aug 29 19:51:38 donquixotevolumio systemd[1]: Starting Music Player Daemon... Aug 29 19:51:38 donquixotevolumio sudo[1169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 19:51:38 donquixotevolumio sudo[1169]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:38 donquixotevolumio sudo[1169]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: [1724986298710] CoreMusicLibrary::Adding element Media Servers Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 19:51:38 donquixotevolumio sudo[1173]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 19:51:38 donquixotevolumio sudo[1173]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:38 donquixotevolumio sudo[1170]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 19:51:38 donquixotevolumio sudo[1170]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:38 donquixotevolumio sudo[1170]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 29 19:51:38 donquixotevolumio sudo[1170]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:38 donquixotevolumio systemd[1]: systemd-fsckd.service: Succeeded. Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 19:51:38 donquixotevolumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Aug 29 19:51:38 donquixotevolumio systemd[1]: mpd.service: Succeeded. Aug 29 19:51:38 donquixotevolumio systemd[1]: Stopped Music Player Daemon. Aug 29 19:51:38 donquixotevolumio systemd[1]: Starting Music Player Daemon... Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: [1724986298870] CoreMusicLibrary::Adding element Last_100 Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: [1724986298874] CoreMusicLibrary::Adding element Webradio Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Initializing BBC Radios Aug 29 19:51:38 donquixotevolumio sudo[1196]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 19:51:38 donquixotevolumio sudo[1196]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:38 donquixotevolumio sudo[1196]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 29 19:51:38 donquixotevolumio sudo[1196]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: Creating Spotify config file Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: [1724986298985] CoreMusicLibrary::Adding element YouTube2 Aug 29 19:51:38 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 19:51:38 donquixotevolumio volumio[1051]: Cannot find translation for source YouTube2 Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Volumio Calling Home Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Discovery: adding d756d5f5-5d07-4217-bb12-41f53988e09d Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Discovery: Found device DonQuixoteVolumio Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Discovery: this is already registered, d756d5f5-5d07-4217-bb12-41f53988e09d Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Discovery: Found device DonQuixoteVolumio Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:39 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.68 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: MPD Permissions set Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: MPD Permissions set Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Spotify config file written Aug 29 19:51:39 donquixotevolumio sudo[1224]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 19:51:39 donquixotevolumio sudo[1224]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:39 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Received Get System Info Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Discovery: Getting this device information Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:39 donquixotevolumio systemd[1]: Started go-librespot Daemon. Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:39 donquixotevolumio go-librespot[1226]: Librespot-go daemon starting... Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:39 donquixotevolumio sudo[1224]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Received Get System Info Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Discovery: Getting this device information Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Listing playlists Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetQueue Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreStateMachine::getQueue Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getQueue Aug 29 19:51:39 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Volumio called home Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Starting Shairport Sync Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Starting Shairport Sync Aug 29 19:51:39 donquixotevolumio sudo[1242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: Starting Shairport Sync Aug 29 19:51:39 donquixotevolumio sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:39 donquixotevolumio sudo[1244]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 19:51:39 donquixotevolumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 29 19:51:39 donquixotevolumio sudo[1244]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:39 donquixotevolumio systemd[1]: shairport-sync.service: Succeeded. Aug 29 19:51:39 donquixotevolumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 29 19:51:39 donquixotevolumio sudo[1247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 19:51:39 donquixotevolumio sudo[1247]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:39 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:39 donquixotevolumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 29 19:51:39 donquixotevolumio sudo[1242]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:39 donquixotevolumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 29 19:51:39 donquixotevolumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Aug 29 19:51:39 donquixotevolumio systemd[1]: shairport-sync.service: Succeeded. Aug 29 19:51:39 donquixotevolumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 29 19:51:39 donquixotevolumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 29 19:51:39 donquixotevolumio sudo[1244]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:39 donquixotevolumio sudo[1247]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:39 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:39-07:00" level=info msg="generated new device id: da9f89be0ee219ff5f8411534a21e6307b27c253" Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: Shairport-Sync Started Aug 29 19:51:40 donquixotevolumio volumio[1051]: Error adding Membership: Error: addMembership EINVAL Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: Shairport-Sync Started Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: Shairport-Sync Started Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14 Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 19:51:40 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:40-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 19:51:40 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:40-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 19:51:40 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:40-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 19:51:40 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:40-07:00" level=debug msg="zeroconf server listening on port 36765" Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 15 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 16 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 17 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 18 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 19 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 20 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 21 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 22 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 23 Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: [yt-cast-receiver] DIAL server listening on port 8098 Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: CoreStateMachine::pushState Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:40 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioPushState Aug 29 19:51:40 donquixotevolumio volumio[1051]: error: [ytcr] VolumeControl failed to obtain volume from Volumio: Aug 29 19:51:40 donquixotevolumio volumio[1051]: (TypeError) Cannot read property 'vol' of undefined Aug 29 19:51:40 donquixotevolumio volumio[1051]: TypeError: Cannot read property 'vol' of undefined Aug 29 19:51:40 donquixotevolumio volumio[1051]: at VolumeControl.getVolume (/data/plugins/music_service/ytcr/dist/lib/VolumeControl.js:56:42) Aug 29 19:51:40 donquixotevolumio volumio[1051]: at runMicrotasks () Aug 29 19:51:40 donquixotevolumio volumio[1051]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Aug 29 19:51:40 donquixotevolumio volumio[1051]: at async VolumeControl.init (/data/plugins/music_service/ytcr/dist/lib/VolumeControl.js:28:68) Aug 29 19:51:40 donquixotevolumio volumio[1051]: at async /data/plugins/music_service/ytcr/dist/index.js:310:13 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 24 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 25 Aug 29 19:51:40 donquixotevolumio volumio[1051]: verbose: New Socket.io Connection to 192.168.68.69 from 192.168.68.67 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 26 Aug 29 19:51:40 donquixotevolumio mpd[1202]: Aug 29 19:51 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 29 19:51:41 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 19:51:41 donquixotevolumio systemd[1]: Started Music Player Daemon. Aug 29 19:51:41 donquixotevolumio sudo[1173]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:41 donquixotevolumio sudo[1162]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:41 donquixotevolumio volumio[1051]: info: Completed starting Core Plugins Aug 29 19:51:41 donquixotevolumio volumio[1051]: info: ------------------------------------------- Aug 29 19:51:41 donquixotevolumio volumio[1051]: info: ----- MyVolumio plugins startup ---- Aug 29 19:51:41 donquixotevolumio volumio[1051]: info: ------------------------------------------- Aug 29 19:51:41 donquixotevolumio volumio[1051]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 29 19:51:41 donquixotevolumio volumio[1051]: error: MPD error: The expression evaluated to a falsy value: Aug 29 19:51:41 donquixotevolumio volumio[1051]: assert.ok(self.idling) Aug 29 19:51:41 donquixotevolumio volumio[1051]: error: The expression evaluated to a falsy value: Aug 29 19:51:41 donquixotevolumio volumio[1051]: assert.ok(self.idling) Aug 29 19:51:41 donquixotevolumio volumio[1051]: info: MPD running with PID1202 Aug 29 19:51:41 donquixotevolumio volumio[1051]: ,establishing connection Aug 29 19:51:41 donquixotevolumio volumio[1051]: error: MPD error: The expression evaluated to a falsy value: Aug 29 19:51:41 donquixotevolumio volumio[1051]: assert.ok(self.idling) Aug 29 19:51:41 donquixotevolumio volumio[1051]: error: The expression evaluated to a falsy value: Aug 29 19:51:41 donquixotevolumio volumio[1051]: assert.ok(self.idling) Aug 29 19:51:41 donquixotevolumio volumio[1051]: error: updateQueue error: null Aug 29 19:51:42 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 19:51:42 donquixotevolumio systemd[1]: systemd-hostnamed.service: Succeeded. Aug 29 19:51:42 donquixotevolumio volumio[1051]: info: go-librespot daemon successfully initialized Aug 29 19:51:42 donquixotevolumio sudo[1263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 19:51:42 donquixotevolumio sudo[1263]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:42 donquixotevolumio sudo[1263]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:42 donquixotevolumio sudo[1266]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 19:51:42 donquixotevolumio sudo[1266]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:42 donquixotevolumio sudo[1266]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:42 donquixotevolumio sudo[1269]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 29 19:51:42 donquixotevolumio sudo[1269]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 19:51:43 donquixotevolumio systemd[1]: Started UPnP Renderer front-end to MPD. Aug 29 19:51:43 donquixotevolumio sudo[1269]: pam_unix(sudo:session): session closed for user root Aug 29 19:51:43 donquixotevolumio volumio[1051]: info: Upmpdcli Daemon Started Aug 29 19:51:43 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 19:51:43 donquixotevolumio volumio[1271]: Generating RSA private key, 4096 bit long modulus (2 primes) Aug 29 19:51:44 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 19:51:45 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 19:51:45 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:45-07:00" level=debug msg="obtained new client token: AAArBeYqsvOt7z/Z8H8jgGVrro4O702m1sx1jv7T2ctE1qz73893VboJhyCTmLM9IwBVyR/CC4oGZxj4q/pJ6/d+cDm2xgPe+Jk3alJTG5/iYjNlPFyROjS/JNObAFhdxq4kwrKqR5scP8gceTnN6LXesTCbuPo2ZcttV39eK+/s31Le9RbdHekneumVdjpzs/olW18xDVT9IBHB5PK0kKUebK80Sbg3qAz+Ma+rhYNTLqaKjzdAfclW5eO7lA==" Aug 29 19:51:45 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:45-07:00" level=debug msg="completed keyexchange" Aug 29 19:51:45 donquixotevolumio volumio[1051]: info: Initializing connection to go-librespot Websocket Aug 29 19:51:45 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:45-07:00" level=debug msg="new websocket client" Aug 29 19:51:45 donquixotevolumio volumio[1051]: info: Connection to go-librespot Websocket established Aug 29 19:51:45 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:45-07:00" level=debug msg="completed challenge" Aug 29 19:51:46 donquixotevolumio volumio[1051]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="authenticated as b3hz1y2uoxdx7ee3qj6su0vg9" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="authenticated as b3hz1y2uoxdx7ee3qj6su0vg9" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="dealer connection opened" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=info msg="accepted zeroconf user b3hz1y2uoxdx7ee3qj6su0vg9 from Michael's S23 Ultra" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="received connection id: NTNkOWNhZmItNGYwZi00ZTAxLWE3ZTAtM2E4NDFiYjBjZDllK2RlYWxlcit0Y3A6Ly8wYWNiZDg3My5pcC5ndWMzLnNwb3RpZnkubmV0OjU3MDArQzhBODYzMjY4QzRFOEJCNjk2Q0ZDODExMkJGQUYyRDY5OUIxRDc2QzRDOEQ1QTI2OEY4MDNCOUJCOEI0MzY0RA==" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="put connect state because NEW_DEVICE" Aug 29 19:51:46 donquixotevolumio volumio[1051]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="handling transfer player command from bd2788558ee19ec82fff1371f1778282bd0a184d" Aug 29 19:51:46 donquixotevolumio volumio[1271]: ......................................++++ Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=trace msg="fetched new page 0 with 229 items (list: 229)" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="loading track spotify:track:3dddSORGOA9Pplz9hvOFsH (paused: false, position: -4305803ms)" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=trace msg="emitting websocket event: will_play" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:3dddSORGOA9Pplz9hvOFsH" Aug 29 19:51:46 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:46-07:00" level=debug msg="requested aes key for file c82478cbc0d27d15a98941dd22b0f604f2ac0dd4, gid: 3dddSORGOA9Pplz9hvOFsH" Aug 29 19:51:46 donquixotevolumio volumio[1051]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3dddSORGOA9Pplz9hvOFsH","play_origin":"playlist"}} Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="fetched first chunk of 18, total size is 9383856 bytes" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=trace msg="seek to -4305803ms (diff: -4305803ms, samples: -189885912, bytes: 0)" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=info msg="loaded track \"How Deep Is Your Love\" (uri: spotify:track:3dddSORGOA9Pplz9hvOFsH, paused: false, position: -4305803ms, duration: 255813ms)" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="fetched chunk 1/17, size: 524288" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="fetched chunk 3/17, size: 524288" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=trace msg="emitting websocket event: metadata" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=trace msg="emitting websocket event: active" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="sending successful reply for delaer request" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="fetched chunk 2/17, size: 524288" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=trace msg="emitting websocket event: playing" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1402" Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 29 19:51:47 donquixotevolumio go-librespot[1226]: time="2024-08-29T19:51:47-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1160" Aug 29 19:51:48 donquixotevolumio volumio[1051]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3dddSORGOA9Pplz9hvOFsH","name":"How Deep Is Your Love","artist_names":["Simone Kopmajer"],"album_name":"Nothing's Gonna Change","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0257bdc120e06a8e0643b4b1d2","position":-4305803,"duration":255813,"release_date":"year:2010 month:1 day:1","track_number":3,"disc_number":1}} Aug 29 19:51:48 donquixotevolumio volumio[1051]: SPOTIFY: received: {"type":"active","data":null} Aug 29 19:51:48 donquixotevolumio volumio[1051]: info: Aligning Spotify Volume to Volumio Volume Aug 29 19:51:48 donquixotevolumio volumio[1051]: info: CoreCommandRouter::volumioGetState Aug 29 19:51:48 donquixotevolumio volumio[1051]: info: CorePlayQueue::getTrack 0 Aug 29 19:51:48 donquixotevolumio volumio[1051]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3dddSORGOA9Pplz9hvOFsH","play_origin":"playlist"}} Aug 29 19:51:48 donquixotevolumio volumio[1051]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 19:51:48 donquixotevolumio volumio[1051]: TypeError: Cannot read property 'service' of undefined Aug 29 19:51:48 donquixotevolumio volumio[1051]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at WebSocket.emit (events.js:315:20) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1209:20) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at Receiver.emit (events.js:315:20) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:594:14) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at writeOrBuffer (internal/streams/writable.js:358:12) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1303:35) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at Socket.emit (events.js:315:20) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at addChunk (internal/streams/readable.js:309:12) Aug 29 19:51:48 donquixotevolumio volumio[1051]: at readableAddChunk (internal/streams/readable.js:284:9) Aug 29 19:51:48 donquixotevolumio volumio[1051]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 19:51:48 donquixotevolumio volumio[1271]: ................++++ Aug 29 19:51:48 donquixotevolumio volumio[1271]: e is 65537 (0x010001) Aug 29 19:51:48 donquixotevolumio volumio[1271]: writing RSA key Aug 29 19:51:48 donquixotevolumio sudo[1305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-29 19:50 Aug 29 19:51:48 donquixotevolumio sudo[1305]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"