-- Logs begin at Mon 2024-06-17 13:21:36 PDT, end at Mon 2024-06-17 13:22:12 PDT. -- Jun 17 13:21:36 garage kernel: Booting Linux on physical CPU 0x0 Jun 17 13:21:36 garage 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 Jun 17 13:21:36 garage kernel: CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d Jun 17 13:21:36 garage kernel: CPU: div instructions available: patching division code Jun 17 13:21:36 garage kernel: CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache Jun 17 13:21:36 garage kernel: OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.2 Jun 17 13:21:36 garage kernel: random: crng init done Jun 17 13:21:36 garage kernel: Memory policy: Data cache writealloc Jun 17 13:21:36 garage kernel: Reserved memory: created CMA memory pool at 0x000000002a000000, size 64 MiB Jun 17 13:21:36 garage kernel: OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool Jun 17 13:21:36 garage kernel: Zone ranges: Jun 17 13:21:36 garage kernel: DMA [mem 0x0000000000000000-0x000000002fffffff] Jun 17 13:21:36 garage kernel: Normal empty Jun 17 13:21:36 garage kernel: HighMem [mem 0x0000000030000000-0x00000000fbffffff] Jun 17 13:21:36 garage kernel: Movable zone start for each node Jun 17 13:21:36 garage kernel: Early memory node ranges Jun 17 13:21:36 garage kernel: node 0: [mem 0x0000000000000000-0x0000000037ffffff] Jun 17 13:21:36 garage kernel: node 0: [mem 0x0000000040000000-0x00000000fbffffff] Jun 17 13:21:36 garage kernel: Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff] Jun 17 13:21:36 garage kernel: percpu: Embedded 17 pages/cpu s37012 r8192 d24428 u69632 Jun 17 13:21:36 garage kernel: pcpu-alloc: s37012 r8192 d24428 u69632 alloc=17*4096 Jun 17 13:21:36 garage kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Jun 17 13:21:36 garage kernel: Built 1 zonelists, mobility grouping on. Total pages: 997696 Jun 17 13:21:36 garage 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=DC:A6:32:8A:64:FD 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=db7775c5-9234-4b9a-955e-7341a245d498 imgfile=/volumio_current.sqsh bootpart=UUID=F102-DE29 datapart=UUID=05cb9234-f82c-4e76-8b1a-55140d477512 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Jun 17 13:21:36 garage kernel: Unknown kernel command line parameters "splash nodebug imgpart=UUID=db7775c5-9234-4b9a-955e-7341a245d498 imgfile=/volumio_current.sqsh bootpart=UUID=F102-DE29 datapart=UUID=05cb9234-f82c-4e76-8b1a-55140d477512 uuidconfig=cmdline.txt pcie_aspm=off bootdelay=7 use_kmsg=no", will be passed to user space. Jun 17 13:21:36 garage kernel: Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) Jun 17 13:21:36 garage kernel: Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Jun 17 13:21:36 garage kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Jun 17 13:21:36 garage kernel: software IO TLB: area num 4. Jun 17 13:21:36 garage kernel: software IO TLB: mapped [mem 0x0000000023c90000-0x0000000027c90000] (64MB) Jun 17 13:21:36 garage kernel: Memory: 3796700K/3997696K available (10240K kernel code, 1504K rwdata, 3388K rodata, 2048K init, 638K bss, 135460K reserved, 65536K cma-reserved, 3211264K highmem) Jun 17 13:21:36 garage kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Jun 17 13:21:36 garage kernel: ftrace: allocating 37251 entries in 110 pages Jun 17 13:21:36 garage kernel: ftrace: allocated 110 pages with 5 groups Jun 17 13:21:36 garage kernel: trace event string verifier disabled Jun 17 13:21:36 garage kernel: rcu: Hierarchical RCU implementation. Jun 17 13:21:36 garage kernel: Rude variant of Tasks RCU enabled. Jun 17 13:21:36 garage kernel: Tracing variant of Tasks RCU enabled. Jun 17 13:21:36 garage kernel: rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Jun 17 13:21:36 garage kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Jun 17 13:21:36 garage kernel: GIC: Using split EOI/Deactivate mode Jun 17 13:21:36 garage kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Jun 17 13:21:36 garage kernel: arch_timer: cp15 timer(s) running at 54.00MHz (phys). Jun 17 13:21:36 garage kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns Jun 17 13:21:36 garage kernel: sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns Jun 17 13:21:36 garage kernel: Switching to timer-based delay loop, resolution 18ns Jun 17 13:21:36 garage kernel: Console: colour dummy device 80x30 Jun 17 13:21:36 garage kernel: printk: console [tty1] enabled Jun 17 13:21:36 garage kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000) Jun 17 13:21:36 garage kernel: CPU: Testing write buffer coherency: ok Jun 17 13:21:36 garage kernel: CPU0: Spectre BHB: enabling loop workaround for all CPUs Jun 17 13:21:36 garage kernel: pid_max: default: 32768 minimum: 301 Jun 17 13:21:36 garage kernel: LSM: Security Framework initializing Jun 17 13:21:36 garage kernel: Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Jun 17 13:21:36 garage kernel: Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Jun 17 13:21:36 garage kernel: cgroup: Disabling memory control group subsystem Jun 17 13:21:36 garage kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Jun 17 13:21:36 garage kernel: cblist_init_generic: Setting adjustable number of callback queues. Jun 17 13:21:36 garage kernel: cblist_init_generic: Setting shift to 2 and lim to 1. Jun 17 13:21:36 garage kernel: cblist_init_generic: Setting adjustable number of callback queues. Jun 17 13:21:36 garage kernel: cblist_init_generic: Setting shift to 2 and lim to 1. Jun 17 13:21:36 garage kernel: Setting up static identity map for 0x200000 - 0x20003c Jun 17 13:21:36 garage kernel: rcu: Hierarchical SRCU implementation. Jun 17 13:21:36 garage kernel: rcu: Max phase no-delay instances is 1000. Jun 17 13:21:36 garage kernel: smp: Bringing up secondary CPUs ... Jun 17 13:21:36 garage kernel: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Jun 17 13:21:36 garage kernel: CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Jun 17 13:21:36 garage kernel: CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Jun 17 13:21:36 garage kernel: smp: Brought up 1 node, 4 CPUs Jun 17 13:21:36 garage kernel: SMP: Total of 4 processors activated (432.00 BogoMIPS). Jun 17 13:21:36 garage kernel: CPU: All CPU(s) started in HYP mode. Jun 17 13:21:36 garage kernel: CPU: Virtualization extensions available. Jun 17 13:21:36 garage kernel: devtmpfs: initialized Jun 17 13:21:36 garage kernel: VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0 Jun 17 13:21:36 garage kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Jun 17 13:21:36 garage kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Jun 17 13:21:36 garage kernel: pinctrl core: initialized pinctrl subsystem Jun 17 13:21:36 garage kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Jun 17 13:21:36 garage kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Jun 17 13:21:36 garage kernel: audit: initializing netlink subsys (disabled) Jun 17 13:21:36 garage kernel: audit: type=2000 audit(0.020:1): state=initialized audit_enabled=0 res=1 Jun 17 13:21:36 garage kernel: thermal_sys: Registered thermal governor 'step_wise' Jun 17 13:21:36 garage kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Jun 17 13:21:36 garage kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Jun 17 13:21:36 garage kernel: Serial: AMBA PL011 UART driver Jun 17 13:21:36 garage kernel: bcm2835-mbox fe00b880.mailbox: mailbox enabled Jun 17 13:21:36 garage kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2023-10-17T15:39:16, variant start Jun 17 13:21:36 garage kernel: raspberrypi-firmware soc:firmware: Firmware hash is 30f0c5e4d076da3ab4f341d88e7d505760b93ad7 Jun 17 13:21:36 garage kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Jun 17 13:21:36 garage kernel: bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 Jun 17 13:21:36 garage kernel: SCSI subsystem initialized Jun 17 13:21:36 garage kernel: usbcore: registered new interface driver usbfs Jun 17 13:21:36 garage kernel: usbcore: registered new interface driver hub Jun 17 13:21:36 garage kernel: usbcore: registered new device driver usb Jun 17 13:21:36 garage kernel: usb_phy_generic phy: supply vcc not found, using dummy regulator Jun 17 13:21:36 garage kernel: pps_core: LinuxPPS API ver. 1 registered Jun 17 13:21:36 garage kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti Jun 17 13:21:36 garage kernel: PTP clock support registered Jun 17 13:21:36 garage kernel: vgaarb: loaded Jun 17 13:21:36 garage kernel: clocksource: Switched to clocksource arch_sys_counter Jun 17 13:21:36 garage kernel: VFS: Disk quotas dquot_6.6.0 Jun 17 13:21:36 garage kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Jun 17 13:21:36 garage kernel: FS-Cache: Loaded Jun 17 13:21:36 garage kernel: CacheFiles: Loaded Jun 17 13:21:36 garage kernel: NET: Registered PF_INET protocol family Jun 17 13:21:36 garage kernel: IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) Jun 17 13:21:36 garage kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear) Jun 17 13:21:36 garage kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Jun 17 13:21:36 garage kernel: TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) Jun 17 13:21:36 garage kernel: TCP bind hash table entries: 8192 (order: 5, 131072 bytes, linear) Jun 17 13:21:36 garage kernel: TCP: Hash tables configured (established 8192 bind 8192) Jun 17 13:21:36 garage kernel: UDP hash table entries: 512 (order: 2, 16384 bytes, linear) Jun 17 13:21:36 garage kernel: UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) Jun 17 13:21:36 garage kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Jun 17 13:21:36 garage kernel: RPC: Registered named UNIX socket transport module. Jun 17 13:21:36 garage kernel: RPC: Registered udp transport module. Jun 17 13:21:36 garage kernel: RPC: Registered tcp transport module. Jun 17 13:21:36 garage kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Jun 17 13:21:36 garage kernel: PCI: CLS 0 bytes, default 64 Jun 17 13:21:36 garage kernel: Trying to unpack rootfs image as initramfs... Jun 17 13:21:36 garage kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available Jun 17 13:21:36 garage kernel: Initialise system trusted keyrings Jun 17 13:21:36 garage kernel: workingset: timestamp_bits=14 max_order=20 bucket_order=6 Jun 17 13:21:36 garage kernel: zbud: loaded Jun 17 13:21:36 garage kernel: NFS: Registering the id_resolver key type Jun 17 13:21:36 garage kernel: Key type id_resolver registered Jun 17 13:21:36 garage kernel: Key type id_legacy registered Jun 17 13:21:36 garage kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Jun 17 13:21:36 garage kernel: nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Jun 17 13:21:36 garage kernel: Key type asymmetric registered Jun 17 13:21:36 garage kernel: Asymmetric key parser 'x509' registered Jun 17 13:21:36 garage kernel: bounce: pool size: 64 pages Jun 17 13:21:36 garage kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) Jun 17 13:21:36 garage kernel: io scheduler mq-deadline registered Jun 17 13:21:36 garage kernel: io scheduler kyber registered Jun 17 13:21:36 garage kernel: brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: Jun 17 13:21:36 garage kernel: brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] Jun 17 13:21:36 garage kernel: brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 Jun 17 13:21:36 garage kernel: brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000 Jun 17 13:21:36 garage kernel: brcm-pcie fd500000.pcie: setting SCB_ACCESS_EN, READ_UR_MODE, MAX_BURST_SIZE Jun 17 13:21:36 garage kernel: brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 Jun 17 13:21:36 garage kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Jun 17 13:21:36 garage kernel: pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) Jun 17 13:21:36 garage kernel: pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 Jun 17 13:21:36 garage kernel: pci 0000:00:00.0: PME# supported from D0 D3hot Jun 17 13:21:36 garage kernel: PCI: bus0: Fast back to back transfers disabled Jun 17 13:21:36 garage kernel: pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring Jun 17 13:21:36 garage kernel: pci_bus 0000:01: supply vpcie3v3 not found, using dummy regulator Jun 17 13:21:36 garage kernel: pci_bus 0000:01: supply vpcie3v3aux not found, using dummy regulator Jun 17 13:21:36 garage kernel: pci_bus 0000:01: supply vpcie12v not found, using dummy regulator Jun 17 13:21:36 garage kernel: brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) Jun 17 13:21:36 garage kernel: pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 Jun 17 13:21:36 garage kernel: pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] Jun 17 13:21:36 garage kernel: pci 0000:01:00.0: PME# supported from D0 D3cold Jun 17 13:21:36 garage kernel: PCI: bus1: Fast back to back transfers disabled Jun 17 13:21:36 garage kernel: pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01 Jun 17 13:21:36 garage kernel: pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] Jun 17 13:21:36 garage kernel: pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] Jun 17 13:21:36 garage kernel: pci 0000:00:00.0: PCI bridge to [bus 01] Jun 17 13:21:36 garage kernel: pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] Jun 17 13:21:36 garage kernel: pci 0000:00:00.0: Max Payload Size set to 256/ 512 (was 128), Max Read Rq 512 Jun 17 13:21:36 garage kernel: pci 0000:01:00.0: Max Payload Size set to 256/ 256 (was 128), Max Read Rq 512 Jun 17 13:21:36 garage kernel: pcieport 0000:00:00.0: enabling device (0000 -> 0002) Jun 17 13:21:36 garage kernel: pcieport 0000:00:00.0: PME: Signaling with IRQ 45 Jun 17 13:21:36 garage kernel: bcm2708_fb soc:fb: FB found 1 display(s) Jun 17 13:21:36 garage kernel: Console: switching to colour frame buffer device 80x30 Jun 17 13:21:36 garage kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Jun 17 13:21:36 garage kernel: iproc-rng200 fe104000.rng: hwrng registered Jun 17 13:21:36 garage kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Jun 17 13:21:36 garage kernel: brd: module loaded Jun 17 13:21:36 garage kernel: loop: module loaded Jun 17 13:21:36 garage kernel: Loading iSCSI transport class v2.0-870. Jun 17 13:21:36 garage kernel: bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 Jun 17 13:21:36 garage kernel: Freeing initrd memory: 14316K Jun 17 13:21:36 garage kernel: unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus Jun 17 13:21:36 garage kernel: usbcore: registered new device driver r8152-cfgselector Jun 17 13:21:36 garage kernel: usbcore: registered new interface driver r8152 Jun 17 13:21:36 garage kernel: usbcore: registered new interface driver lan78xx Jun 17 13:21:36 garage kernel: usbcore: registered new interface driver smsc95xx Jun 17 13:21:36 garage kernel: xhci_hcd 0000:01:00.0: enabling device (0140 -> 0142) Jun 17 13:21:36 garage kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Jun 17 13:21:36 garage kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 Jun 17 13:21:36 garage kernel: xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0f00040000000890 Jun 17 13:21:36 garage kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Jun 17 13:21:36 garage kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Jun 17 13:21:36 garage kernel: xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Jun 17 13:21:36 garage kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.01 Jun 17 13:21:36 garage kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Jun 17 13:21:36 garage kernel: usb usb1: Product: xHCI Host Controller Jun 17 13:21:36 garage kernel: usb usb1: Manufacturer: Linux 6.1.77-v7l+ xhci-hcd Jun 17 13:21:36 garage kernel: usb usb1: SerialNumber: 0000:01:00.0 Jun 17 13:21:36 garage kernel: hub 1-0:1.0: USB hub found Jun 17 13:21:36 garage kernel: hub 1-0:1.0: 1 port detected Jun 17 13:21:36 garage kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.01 Jun 17 13:21:36 garage kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Jun 17 13:21:36 garage kernel: usb usb2: Product: xHCI Host Controller Jun 17 13:21:36 garage kernel: usb usb2: Manufacturer: Linux 6.1.77-v7l+ xhci-hcd Jun 17 13:21:36 garage kernel: usb usb2: SerialNumber: 0000:01:00.0 Jun 17 13:21:36 garage kernel: hub 2-0:1.0: USB hub found Jun 17 13:21:36 garage kernel: hub 2-0:1.0: 4 ports detected Jun 17 13:21:36 garage kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Jun 17 13:21:36 garage kernel: dwc_otg: FIQ enabled Jun 17 13:21:36 garage kernel: dwc_otg: NAK holdoff enabled Jun 17 13:21:36 garage kernel: dwc_otg: FIQ split-transaction FSM enabled Jun 17 13:21:36 garage kernel: Module dwc_common_port init Jun 17 13:21:36 garage kernel: usbcore: registered new interface driver uas Jun 17 13:21:36 garage kernel: usbcore: registered new interface driver usb-storage Jun 17 13:21:36 garage kernel: mousedev: PS/2 mouse device common for all mice Jun 17 13:21:36 garage kernel: sdhci: Secure Digital Host Controller Interface driver Jun 17 13:21:36 garage kernel: sdhci: Copyright(c) Pierre Ossman Jun 17 13:21:36 garage kernel: sdhci-pltfm: SDHCI platform and OF driver helper Jun 17 13:21:36 garage kernel: ledtrig-cpu: registered to indicate activity on CPUs Jun 17 13:21:36 garage kernel: hid: raw HID events driver (C) Jiri Kosina Jun 17 13:21:36 garage kernel: usbcore: registered new interface driver usbhid Jun 17 13:21:36 garage kernel: usbhid: USB HID core driver Jun 17 13:21:36 garage kernel: Initializing XFRM netlink socket Jun 17 13:21:36 garage kernel: NET: Registered PF_PACKET protocol family Jun 17 13:21:36 garage kernel: Key type dns_resolver registered Jun 17 13:21:36 garage kernel: Registering SWP/SWPB emulation handler Jun 17 13:21:36 garage kernel: registered taskstats version 1 Jun 17 13:21:36 garage kernel: Loading compiled-in X.509 certificates Jun 17 13:21:36 garage kernel: Key type .fscrypt registered Jun 17 13:21:36 garage kernel: Key type fscrypt-provisioning registered Jun 17 13:21:36 garage kernel: uart-pl011 fe201000.serial: there is not valid maps for state default Jun 17 13:21:36 garage kernel: uart-pl011 fe201000.serial: cts_event_workaround enabled Jun 17 13:21:36 garage kernel: fe201000.serial: ttyAMA1 at MMIO 0xfe201000 (irq = 51, base_baud = 0) is a PL011 rev2 Jun 17 13:21:36 garage kernel: serial serial0: tty port ttyAMA1 registered Jun 17 13:21:36 garage kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Jun 17 13:21:36 garage kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Jun 17 13:21:36 garage kernel: mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 Jun 17 13:21:36 garage kernel: mmc-bcm2835 fe300000.mmcnr: DMA channel allocated Jun 17 13:21:36 garage kernel: of_cfs_init Jun 17 13:21:36 garage kernel: of_cfs_init: OK Jun 17 13:21:36 garage kernel: mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA Jun 17 13:21:36 garage kernel: Freeing unused kernel image (initmem) memory: 2048K Jun 17 13:21:36 garage kernel: Run /init as init process Jun 17 13:21:36 garage kernel: with arguments: Jun 17 13:21:36 garage kernel: /init Jun 17 13:21:36 garage kernel: splash Jun 17 13:21:36 garage kernel: nodebug Jun 17 13:21:36 garage kernel: with environment: Jun 17 13:21:36 garage kernel: HOME=/ Jun 17 13:21:36 garage kernel: TERM=linux Jun 17 13:21:36 garage kernel: imgpart=UUID=db7775c5-9234-4b9a-955e-7341a245d498 Jun 17 13:21:36 garage kernel: imgfile=/volumio_current.sqsh Jun 17 13:21:36 garage kernel: bootpart=UUID=F102-DE29 Jun 17 13:21:36 garage kernel: datapart=UUID=05cb9234-f82c-4e76-8b1a-55140d477512 Jun 17 13:21:36 garage kernel: uuidconfig=cmdline.txt Jun 17 13:21:36 garage kernel: pcie_aspm=off Jun 17 13:21:36 garage kernel: bootdelay=7 Jun 17 13:21:36 garage kernel: use_kmsg=no Jun 17 13:21:36 garage kernel: mmc1: new high speed SDIO card at address 0001 Jun 17 13:21:36 garage kernel: mmc0: new ultra high speed DDR50 SDHC card at address 0007 Jun 17 13:21:36 garage kernel: mmcblk0: mmc0:0007 SD16G 14.5 GiB Jun 17 13:21:36 garage kernel: mmcblk0: p1 p2 p3 Jun 17 13:21:36 garage kernel: mmcblk0: mmc0:0007 SD16G 14.5 GiB Jun 17 13:21:36 garage kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd Jun 17 13:21:36 garage kernel: usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.20 Jun 17 13:21:36 garage kernel: usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Jun 17 13:21:36 garage kernel: usb 1-1: Product: USB2.0 Hub Jun 17 13:21:36 garage kernel: hub 1-1:1.0: USB hub found Jun 17 13:21:36 garage kernel: hub 1-1:1.0: 4 ports detected Jun 17 13:21:36 garage kernel: fuse: init (API version 7.37) Jun 17 13:21:36 garage kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Jun 17 13:21:36 garage kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Jun 17 13:21:36 garage kernel: EXT4-fs (mmcblk0p2): recovery complete Jun 17 13:21:36 garage kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none. Jun 17 13:21:36 garage kernel: loop0: detected capacity change from 0 to 979240 Jun 17 13:21:36 garage kernel: EXT4-fs (mmcblk0p3): recovery complete Jun 17 13:21:36 garage kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Quota mode: none. Jun 17 13:21:36 garage systemd[1]: System time before build time, advancing clock. Jun 17 13:21:36 garage kernel: NET: Registered PF_INET6 protocol family Jun 17 13:21:36 garage kernel: Segment Routing with IPv6 Jun 17 13:21:36 garage kernel: In-situ OAM (IOAM) with IPv6 Jun 17 13:21:36 garage systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) Jun 17 13:21:36 garage systemd[1]: Detected architecture arm. Jun 17 13:21:36 garage systemd[1]: Set hostname to . Jun 17 13:21:36 garage systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Jun 17 13:21:36 garage systemd[1]: Created slice system-getty.slice. Jun 17 13:21:36 garage systemd[1]: Listening on udev Control Socket. Jun 17 13:21:36 garage systemd[1]: Listening on Journal Socket (/dev/log). Jun 17 13:21:36 garage systemd[1]: Created slice system-systemd\x2dfsck.slice. Jun 17 13:21:36 garage systemd[1]: Listening on fsck to fsckd communication Socket. Jun 17 13:21:36 garage systemd[1]: Listening on Journal Socket. Jun 17 13:21:36 garage kernel: i2c_dev: i2c /dev entries driver Jun 17 13:21:36 garage systemd-journald[322]: Journal started Jun 17 13:21:36 garage systemd-journald[322]: Runtime journal (/run/log/journal/32836d460d421189c56ead0a6628f62c) is 3.7M, max 30.0M, 26.2M free. Jun 17 13:21:36 garage systemd-modules-load[308]: Inserted module 'i2c_dev' Jun 17 13:21:36 garage systemd[1]: dynamicswap.service: Succeeded. Jun 17 13:21:36 garage fake-hwclock[310]: Mon Jun 17 20:21:36 UTC 2024 Jun 17 13:21:36 garage systemd[1]: Started Create System Users. Jun 17 13:21:36 garage systemd[1]: Starting Create Static Device Nodes in /dev... Jun 17 13:21:36 garage systemd[1]: Started Create Static Device Nodes in /dev. Jun 17 13:21:36 garage systemd[1]: Reached target Local File Systems (Pre). Jun 17 13:21:36 garage systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Jun 17 13:21:36 garage systemd[1]: Mounting /tmp... Jun 17 13:21:36 garage systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Jun 17 13:21:36 garage systemd[1]: Mounting /var/log... Jun 17 13:21:36 garage systemd[1]: Mounting /var/spool/cups... Jun 17 13:21:36 garage systemd[1]: Starting udev Kernel Device Manager... Jun 17 13:21:36 garage systemd[1]: Started udev Coldplug all Devices. Jun 17 13:21:36 garage systemd[1]: Mounted /tmp. Jun 17 13:21:36 garage systemd[1]: Mounted /var/log. Jun 17 13:21:36 garage systemd[1]: Mounted /var/spool/cups. Jun 17 13:21:36 garage systemd[1]: Mounting /var/spool/cups/tmp... Jun 17 13:21:36 garage systemd[1]: Starting Flush Journal to Persistent Storage... Jun 17 13:21:36 garage systemd[1]: Starting Helper to synchronize boot up for ifupdown... Jun 17 13:21:36 garage systemd[1]: Mounted /var/spool/cups/tmp. Jun 17 13:21:36 garage systemd-udevd[344]: Network interface NamePolicy= disabled on kernel command line, ignoring. Jun 17 13:21:36 garage systemd[1]: Started Helper to synchronize boot up for ifupdown. Jun 17 13:21:36 garage systemd-journald[322]: Runtime journal (/run/log/journal/32836d460d421189c56ead0a6628f62c) is 3.7M, max 30.0M, 26.2M free. Jun 17 13:21:36 garage systemd[1]: Started Flush Journal to Persistent Storage. Jun 17 13:21:36 garage systemd[1]: Started udev Kernel Device Manager. Jun 17 13:21:36 garage systemd[1]: Starting Show Plymouth Boot Screen... Jun 17 13:21:36 garage systemd[1]: plymouth-start.service: Succeeded. Jun 17 13:21:36 garage systemd[1]: Started Show Plymouth Boot Screen. Jun 17 13:21:36 garage systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Jun 17 13:21:36 garage systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jun 17 13:21:36 garage systemd[1]: Reached target Paths. Jun 17 13:21:36 garage systemd[1]: Reached target Local Encrypted Volumes. Jun 17 13:21:36 garage systemd-udevd[355]: Using default interface naming scheme 'v240'. Jun 17 13:21:36 garage systemd-udevd[355]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jun 17 13:21:36 garage kernel: mc: Linux media interface: v0.10 Jun 17 13:21:36 garage kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Jun 17 13:21:36 garage kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Jun 17 13:21:36 garage kernel: [vc_sm_connected_init]: start Jun 17 13:21:36 garage kernel: [vc_sm_connected_init]: installed successfully Jun 17 13:21:36 garage kernel: rpi-gpiomem fe200000.gpiomem: window base 0xfe200000 size 0x00001000 Jun 17 13:21:36 garage kernel: rpi-gpiomem fe200000.gpiomem: initialised 1 regions as /dev/gpiomem Jun 17 13:21:37 garage kernel: videodev: Linux video capture interface: v2.00 Jun 17 13:21:37 garage systemd-udevd[349]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jun 17 13:21:37 garage kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Jun 17 13:21:37 garage kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Jun 17 13:21:37 garage kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. Jun 17 13:21:37 garage kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Jun 17 13:21:37 garage kernel: rpivid feb10000.codec: Device registered as /dev/video19 Jun 17 13:21:37 garage kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Jun 17 13:21:37 garage kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Jun 17 13:21:37 garage kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Jun 17 13:21:37 garage kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Jun 17 13:21:37 garage kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Jun 17 13:21:37 garage kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Jun 17 13:21:37 garage kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jun 17 13:21:37 garage kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Jun 17 13:21:37 garage kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Jun 17 13:21:37 garage systemd[1]: Found device /dev/disk/by-uuid/F102-DE29. Jun 17 13:21:37 garage kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Jun 17 13:21:37 garage kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jun 17 13:21:37 garage kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Jun 17 13:21:37 garage kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Jun 17 13:21:37 garage kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Jun 17 13:21:37 garage kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Jun 17 13:21:37 garage kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Jun 17 13:21:38 garage kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Jun 17 13:21:38 garage kernel: Bluetooth: Core ver 2.22 Jun 17 13:21:38 garage kernel: NET: Registered PF_BLUETOOTH protocol family Jun 17 13:21:38 garage kernel: Bluetooth: HCI device and connection manager initialized Jun 17 13:21:38 garage kernel: Bluetooth: HCI socket layer initialized Jun 17 13:21:38 garage kernel: Bluetooth: L2CAP socket layer initialized Jun 17 13:21:38 garage kernel: Bluetooth: SCO socket layer initialized Jun 17 13:21:38 garage kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Jun 17 13:21:38 garage kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Jun 17 13:21:38 garage kernel: cfg80211: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Jun 17 13:21:38 garage kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Jun 17 13:21:38 garage kernel: Bluetooth: HCI UART driver ver 2.3 Jun 17 13:21:38 garage kernel: Bluetooth: HCI UART protocol H4 registered Jun 17 13:21:38 garage kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Jun 17 13:21:38 garage kernel: Bluetooth: HCI UART protocol Broadcom registered Jun 17 13:21:38 garage kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Jun 17 13:21:38 garage kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Jun 17 13:21:38 garage kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Jun 17 13:21:38 garage kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Jun 17 13:21:38 garage kernel: usbcore: registered new interface driver brcmfmac Jun 17 13:21:38 garage systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Jun 17 13:21:38 garage kernel: uart-pl011 fe201000.serial: no DMA platform data Jun 17 13:21:38 garage kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 Jun 17 13:21:38 garage kernel: Bluetooth: hci0: BCM: chip id 107 Jun 17 13:21:38 garage kernel: Bluetooth: hci0: BCM: features 0x2f Jun 17 13:21:38 garage kernel: Bluetooth: hci0: BCM4345C0 Jun 17 13:21:38 garage kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Jun 17 13:21:38 garage systemd-udevd[369]: Using default interface naming scheme 'v240'. Jun 17 13:21:38 garage systemd-udevd[369]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jun 17 13:21:38 garage kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Jun 17 13:21:39 garage systemd[1]: Created slice system-bthelper.slice. Jun 17 13:21:39 garage systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Jun 17 13:21:39 garage systemd[1]: Condition check resulted in Huge Pages File System being skipped. Jun 17 13:21:39 garage systemd[1]: Starting Show Plymouth Boot Screen... Jun 17 13:21:39 garage systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Jun 17 13:21:39 garage systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Jun 17 13:21:39 garage systemd[1]: Starting File System Check on /dev/disk/by-uuid/F102-DE29... Jun 17 13:21:39 garage systemd[1]: plymouth-start.service: Succeeded. Jun 17 13:21:39 garage systemd[1]: Started Show Plymouth Boot Screen. Jun 17 13:21:39 garage systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jun 17 13:21:39 garage systemd[1]: Starting Load/Save RF Kill Switch Status... Jun 17 13:21:39 garage systemd[1]: Started File System Check Daemon to report status. Jun 17 13:21:39 garage systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Jun 17 13:21:39 garage systemd[1]: Started Load/Save RF Kill Switch Status. Jun 17 13:21:39 garage kernel: Bluetooth: hci0: BCM: features 0x2f Jun 17 13:21:39 garage kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Jun 17 13:21:39 garage kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Jun 17 13:21:39 garage systemd-fsck[509]: fsck.fat 4.1 (2017-01-24) Jun 17 13:21:39 garage systemd-fsck[509]: 0x25: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Jun 17 13:21:39 garage systemd-fsck[509]: Automatically removing dirty bit. Jun 17 13:21:39 garage systemd-fsck[509]: Performing changes. Jun 17 13:21:39 garage systemd-fsck[509]: /dev/mmcblk0p1: 369 files, 33663/46774 clusters Jun 17 13:21:39 garage systemd[1]: Started File System Check on /dev/disk/by-uuid/F102-DE29. Jun 17 13:21:39 garage systemd[1]: Mounting /boot... Jun 17 13:21:39 garage systemd[1]: Mounted /boot. Jun 17 13:21:39 garage systemd[1]: Reached target Local File Systems. Jun 17 13:21:39 garage systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Jun 17 13:21:39 garage systemd[1]: Started ifup for wlan0. Jun 17 13:21:39 garage systemd[1]: Starting Preprocess NFS configuration... Jun 17 13:21:39 garage systemd[1]: Started ifup for eth0. Jun 17 13:21:39 garage systemd[1]: Starting Create Volatile Files and Directories... Jun 17 13:21:39 garage systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Jun 17 13:21:39 garage systemd[1]: Starting Raise network interfaces... Jun 17 13:21:39 garage systemd[1]: plymouth-read-write.service: Succeeded. Jun 17 13:21:39 garage systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Jun 17 13:21:39 garage systemd[1]: Received SIGRTMIN+20 from PID 207 (plymouthd). Jun 17 13:21:39 garage systemd[1]: nfs-config.service: Succeeded. Jun 17 13:21:39 garage systemd[1]: Started Preprocess NFS configuration. Jun 17 13:21:39 garage systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Jun 17 13:21:39 garage systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Jun 17 13:21:39 garage systemd[1]: Reached target NFS client services. Jun 17 13:21:39 garage systemd[1]: Started Create Volatile Files and Directories. Jun 17 13:21:39 garage systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Jun 17 13:21:39 garage systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Jun 17 13:21:40 garage systemd[1]: Starting RPC bind portmap service... Jun 17 13:21:40 garage systemd[1]: Starting Update UTMP about System Boot/Shutdown... Jun 17 13:21:40 garage kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 17 13:21:40 garage kernel: 8021q: 802.1Q VLAN Support v1.8 Jun 17 13:21:40 garage systemd[1]: Started Update UTMP about System Boot/Shutdown. Jun 17 13:21:40 garage systemd[1]: Reached target System Initialization. Jun 17 13:21:40 garage systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Jun 17 13:21:40 garage systemd[1]: Started Daily Cleanup of Temporary Directories. Jun 17 13:21:40 garage systemd[1]: apt-daily.timer: Not using persistent file timestamp Sat 2024-07-13 09:14:09 PDT as it is in the future. Jun 17 13:21:40 garage systemd[1]: Started Daily apt download activities. Jun 17 13:21:40 garage systemd[1]: apt-daily-upgrade.timer: Not using persistent file timestamp Sat 2024-07-13 09:14:09 PDT as it is in the future. Jun 17 13:21:40 garage systemd[1]: Started Daily apt upgrade and clean activities. Jun 17 13:21:40 garage systemd[1]: Reached target Timers. Jun 17 13:21:40 garage systemd[1]: Listening on D-Bus System Message Bus Socket. Jun 17 13:21:40 garage systemd[1]: Listening on triggerhappy.socket. Jun 17 13:21:40 garage systemd[1]: Reached target Sockets. Jun 17 13:21:40 garage systemd[1]: Reached target Basic System. Jun 17 13:21:40 garage systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Jun 17 13:21:40 garage systemd[1]: Started Manage Sound Card State (restore and store). Jun 17 13:21:40 garage systemd[1]: Started D-Bus System Message Bus. Jun 17 13:21:40 garage alsactl[604]: alsactl 1.1.8 daemon started Jun 17 13:21:40 garage systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Jun 17 13:21:40 garage systemd[1]: Started volumio-remote-updater.service. Jun 17 13:21:40 garage systemd[1]: Starting triggerhappy global hotkey daemon... Jun 17 13:21:40 garage systemd[1]: Starting Configure Bluetooth Modems connected by UART... Jun 17 13:21:40 garage systemd[1]: Started Volumio Log Rotation Service. Jun 17 13:21:40 garage systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Jun 17 13:21:40 garage systemd[1]: Starting Wireless Services... Jun 17 13:21:40 garage systemd[1]: Started UPnP Renderer front-end to MPD. Jun 17 13:21:40 garage systemd[1]: Started Volumio Iptables Module. Jun 17 13:21:40 garage systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Jun 17 13:21:40 garage systemd[1]: Starting dhcpcd on all interfaces... Jun 17 13:21:40 garage systemd[1]: Starting Save/Restore Sound Card State... Jun 17 13:21:40 garage systemd[1]: Starting Login Service... Jun 17 13:21:40 garage systemd[1]: Starting WPA supplicant... Jun 17 13:21:40 garage systemd[1]: Started RPC bind portmap service. Jun 17 13:21:40 garage systemd[1]: Reached target RPC Port Mapper. Jun 17 13:21:40 garage systemd[1]: Reached target Remote File Systems (Pre). Jun 17 13:21:40 garage systemd[1]: Reached target Remote File Systems. Jun 17 13:21:40 garage thd[619]: Unable to parse trigger line: Jun 17 13:21:40 garage thd[619]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Jun 17 13:21:40 garage thd[619]: Unable to parse trigger line: Jun 17 13:21:40 garage thd[619]: Found socket passed from systemd Jun 17 13:21:40 garage dhcpcd[631]: Not running dhcpcd because /etc/network/interfaces Jun 17 13:21:40 garage dhcpcd[631]: defines some interfaces that will use a Jun 17 13:21:40 garage dhcpcd[631]: DHCP client or static address Jun 17 13:21:40 garage systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Jun 17 13:21:40 garage avahi-daemon[623]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Jun 17 13:21:40 garage systemd[1]: Started triggerhappy global hotkey daemon. Jun 17 13:21:40 garage avahi-daemon[623]: Successfully dropped root privileges. Jun 17 13:21:40 garage systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Jun 17 13:21:40 garage avahi-daemon[623]: avahi-daemon 0.7 starting up. Jun 17 13:21:40 garage systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Jun 17 13:21:40 garage systemd[1]: Failed to start dhcpcd on all interfaces. Jun 17 13:21:40 garage systemd[1]: Started Save/Restore Sound Card State. Jun 17 13:21:40 garage sh[520]: wlan0=wlan0 Jun 17 13:21:40 garage systemd[1]: Reached target Sound Card. Jun 17 13:21:41 garage systemd-logind[634]: New seat seat0. Jun 17 13:21:41 garage sh[523]: eth0: waiting for carrier Jun 17 13:21:41 garage kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Jun 17 13:21:41 garage dhcpcd[568]: eth0: waiting for carrier Jun 17 13:21:41 garage kernel: bcmgenet fd580000.ethernet eth0: Link is Down Jun 17 13:21:41 garage systemd[1]: hciuart.service: Succeeded. Jun 17 13:21:41 garage systemd[1]: Started Configure Bluetooth Modems connected by UART. Jun 17 13:21:41 garage wpa_supplicant[635]: Successfully initialized wpa_supplicant Jun 17 13:21:41 garage avahi-daemon[623]: Successfully called chroot(). Jun 17 13:21:41 garage avahi-daemon[623]: Successfully dropped remaining capabilities. Jun 17 13:21:41 garage avahi-daemon[623]: Loading service file /services/volumio.service. Jun 17 13:21:42 garage avahi-daemon[623]: Network interface enumeration completed. Jun 17 13:21:42 garage avahi-daemon[623]: Server startup complete. Host name is garage.local. Local service cookie is 306847872. Jun 17 13:21:42 garage avahi-daemon[623]: Service "Garage" (/services/volumio.service) successfully established. Jun 17 13:21:42 garage systemd[1]: Started Login Service. Jun 17 13:21:42 garage systemd[1]: Started WPA supplicant. Jun 17 13:21:42 garage systemd[1]: Started Raise network interfaces. Jun 17 13:21:42 garage systemd[1]: Started Avahi mDNS/DNS-SD Stack. Jun 17 13:21:42 garage systemd[1]: Reached target Network. Jun 17 13:21:42 garage systemd[1]: Starting Network Time Service... Jun 17 13:21:42 garage systemd[1]: Reached target Network is Online. Jun 17 13:21:42 garage systemd[1]: Starting LSB: Brings up/down network automatically... Jun 17 13:21:42 garage systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 17 13:21:42 garage systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Jun 17 13:21:42 garage systemd[1]: Starting Samba NMB Daemon... Jun 17 13:21:42 garage systemd[1]: Starting /etc/rc.local Compatibility... Jun 17 13:21:42 garage systemd[1]: Starting Permit User Sessions... Jun 17 13:21:42 garage systemd[1]: Starting Raspberry Pi bluetooth helper... Jun 17 13:21:42 garage systemd[1]: Started /etc/rc.local Compatibility. Jun 17 13:21:42 garage systemd[1]: Started Permit User Sessions. Jun 17 13:21:42 garage volumio-remote-updater[618]: Error: No active session Jun 17 13:21:42 garage systemd[1]: Starting Terminate Plymouth Boot Screen... Jun 17 13:21:42 garage volumio-remote-updater[618]: [2024-06-17 13:21:42] [info] asio async_connect error: system:111 (Connection refused) Jun 17 13:21:42 garage volumio-remote-updater[618]: [2024-06-17 13:21:42] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 17 13:21:42 garage volumio-remote-updater[618]: [2024-06-17 13:21:42] [error] handle_connect error: Underlying Transport Error Jun 17 13:21:42 garage systemd[1]: Starting Hold until boot process finishes up... Jun 17 13:21:42 garage systemd[1]: Received SIGRTMIN+21 from PID 207 (plymouthd). Jun 17 13:21:42 garage bthelper[713]: Raspberry Pi BDADDR already set Jun 17 13:21:42 garage systemd[1]: Started Raspberry Pi bluetooth helper. Jun 17 13:21:42 garage systemd[1]: Starting Bluetooth service... Jun 17 13:21:42 garage systemd[1]: plymouth-quit.service: Succeeded. Jun 17 13:21:42 garage systemd[1]: Started Terminate Plymouth Boot Screen. Jun 17 13:21:42 garage systemd[1]: plymouth-quit-wait.service: Succeeded. Jun 17 13:21:42 garage systemd[1]: Started Hold until boot process finishes up. Jun 17 13:21:42 garage systemd[1]: Received SIGRTMIN+21 from PID 207 (n/a). Jun 17 13:21:42 garage ifplugd(eth0)[762]: ifplugd 0.28 initializing. Jun 17 13:21:42 garage ifplugd(eth0)[762]: Using interface eth0/DC:A6:32:8A:64:FD with driver (version: 6.1.77-v7l+) Jun 17 13:21:42 garage systemd[1]: Started Getty on tty1. Jun 17 13:21:42 garage ifplugd(eth0)[762]: Using detection mode: SIOCETHTOOL Jun 17 13:21:42 garage ifplugd(eth0)[762]: Initialization complete, link beat not detected. Jun 17 13:21:42 garage systemd[1]: Reached target Login Prompts. Jun 17 13:21:42 garage volumio[625]: Could not open config: /tmp/upmpdcli.conf Jun 17 13:21:42 garage loadcpufreq[637]: Loading cpufreq kernel modules...done (none). Jun 17 13:21:42 garage systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Jun 17 13:21:42 garage ifplugd[704]: Network Interface Plugging Daemon...start eth0...done. Jun 17 13:21:42 garage systemd[1]: Starting LSB: set CPUFreq kernel parameters... Jun 17 13:21:42 garage systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jun 17 13:21:42 garage systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jun 17 13:21:42 garage systemd[1]: Started LSB: Brings up/down network automatically. Jun 17 13:21:42 garage systemd[1]: iptables.service: Succeeded. Jun 17 13:21:43 garage ntpd[697]: ntpd 4.2.8p12@1.3728-o (1): Starting Jun 17 13:21:43 garage ntpd[697]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Jun 17 13:21:43 garage systemd[1]: Started Network Time Service. Jun 17 13:21:43 garage ntpd[773]: proto: precision = 2.018 usec (-19) Jun 17 13:21:43 garage ntpd[773]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jun 17 13:21:43 garage ntpd[773]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jun 17 13:21:43 garage ntpd[773]: Listen and drop on 0 v6wildcard [::]:123 Jun 17 13:21:43 garage ntpd[773]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jun 17 13:21:43 garage ntpd[773]: Listen normally on 2 lo 127.0.0.1:123 Jun 17 13:21:43 garage ntpd[773]: Listening on routing socket on fd #19 for interface updates Jun 17 13:21:43 garage ntpd[773]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 17 13:21:43 garage ntpd[773]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 17 13:21:43 garage cpufrequtils[767]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Jun 17 13:21:43 garage systemd[1]: Started LSB: set CPUFreq kernel parameters. Jun 17 13:21:43 garage bluetoothd[748]: Bluetooth daemon 5.50 Jun 17 13:21:43 garage bluetoothd[748]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Jun 17 13:21:43 garage systemd[1]: Started Bluetooth service. Jun 17 13:21:43 garage systemd[1]: Reached target Bluetooth. Jun 17 13:21:43 garage bluetoothd[748]: Starting SDP server Jun 17 13:21:43 garage bluetoothd[748]: Excluding (cli) sap Jun 17 13:21:43 garage bluetoothd[748]: Bluetooth management interface 1.22 initialized Jun 17 13:21:43 garage dbus-daemon[614]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=748 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Jun 17 13:21:43 garage kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Jun 17 13:21:43 garage kernel: Bluetooth: BNEP filters: protocol multicast Jun 17 13:21:43 garage kernel: Bluetooth: BNEP socket layer initialized Jun 17 13:21:43 garage kernel: Bluetooth: MGMT ver 1.22 Jun 17 13:21:43 garage haveged[558]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Jun 17 13:21:43 garage haveged[558]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Jun 17 13:21:43 garage haveged[558]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00158 Jun 17 13:21:43 garage haveged[558]: haveged: fills: 0, generated: 0 Jun 17 13:21:43 garage bluetoothd[748]: Failed to set privacy: Rejected (0x0b) Jun 17 13:21:43 garage systemd[1]: Starting Hostname Service... Jun 17 13:21:43 garage dbus-daemon[614]: [system] Successfully activated service 'org.freedesktop.hostname1' Jun 17 13:21:43 garage systemd[1]: Started Hostname Service. Jun 17 13:21:44 garage systemd[1]: systemd-rfkill.service: Succeeded. Jun 17 13:21:44 garage ntpd[773]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jun 17 13:21:44 garage nmbd[715]: [2024/06/17 13:21:44.911769, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Jun 17 13:21:44 garage nmbd[715]: started asyncdns process 794 Jun 17 13:21:44 garage nmbd[715]: [2024/06/17 13:21:44.915175, 0] ../lib/util/become_daemon.c:149(daemon_status) Jun 17 13:21:44 garage nmbd[715]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Jun 17 13:21:44 garage nmbd[715]: [2024/06/17 13:21:44.915432, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Jun 17 13:21:44 garage nmbd[715]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jun 17 13:21:45 garage ntpd[773]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jun 17 13:21:45 garage wireless.js[624]: Cleaning previous... Jun 17 13:21:45 garage sudo[802]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 17 13:21:45 garage sudo[802]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:45 garage sudo[802]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:45 garage sudo[804]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jun 17 13:21:45 garage sudo[804]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:45 garage kernel: hwmon hwmon1: Undervoltage detected! Jun 17 13:21:45 garage kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off Jun 17 13:21:45 garage ifplugd(eth0)[762]: Link beat detected. Jun 17 13:21:45 garage sh[523]: eth0: carrier acquired Jun 17 13:21:45 garage dhcpcd[568]: eth0: carrier acquired Jun 17 13:21:45 garage sudo[804]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:45 garage sh[523]: DUID 00:01:00:01:2d:bb:b4:8f:dc:a6:32:8a:64:fd Jun 17 13:21:45 garage sh[523]: eth0: IAID 32:8a:64:fd Jun 17 13:21:45 garage dhcpcd[568]: DUID 00:01:00:01:2d:bb:b4:8f:dc:a6:32:8a:64:fd Jun 17 13:21:45 garage dhcpcd[568]: eth0: IAID 32:8a:64:fd Jun 17 13:21:45 garage sh[523]: eth0: adding address fe80::5145:230e:6299:16ad Jun 17 13:21:45 garage sh[523]: ipv6_addaddr1: Permission denied Jun 17 13:21:45 garage dhcpcd[568]: eth0: adding address fe80::5145:230e:6299:16ad Jun 17 13:21:45 garage dhcpcd[568]: ipv6_addaddr1: Permission denied Jun 17 13:21:45 garage wireless.js[624]: Stopped aP Jun 17 13:21:45 garage sudo[812]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jun 17 13:21:45 garage sudo[812]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:46 garage ifplugd(eth0)[762]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Jun 17 13:21:46 garage ntpd[773]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jun 17 13:21:46 garage sh[523]: eth0: soliciting an IPv6 router Jun 17 13:21:46 garage dhcpcd[568]: eth0: soliciting an IPv6 router Jun 17 13:21:46 garage kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 17 13:21:46 garage sudo[812]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:46 garage ifplugd(eth0)[762]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Jun 17 13:21:46 garage sudo[817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Jun 17 13:21:46 garage sudo[817]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:46 garage sudo[817]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:46 garage sudo[826]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jun 17 13:21:46 garage sudo[826]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:46 garage sudo[826]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:46 garage sudo[828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Jun 17 13:21:46 garage sudo[828]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:46 garage sh[523]: eth0: rebinding lease of 10.99.10.123 Jun 17 13:21:46 garage dhcpcd[568]: eth0: rebinding lease of 10.99.10.123 Jun 17 13:21:47 garage ntpd[773]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jun 17 13:21:47 garage kernel: hwmon hwmon1: Voltage normalised Jun 17 13:21:47 garage volumio-remote-updater[618]: [2024-06-17 13:21:47] [info] asio async_connect error: system:111 (Connection refused) Jun 17 13:21:47 garage volumio-remote-updater[618]: [2024-06-17 13:21:47] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 17 13:21:47 garage volumio-remote-updater[618]: [2024-06-17 13:21:47] [error] handle_connect error: Underlying Transport Error Jun 17 13:21:47 garage bthelper[713]: Changing power off succeeded Jun 17 13:21:47 garage bthelper[713]: [CHG] Controller DC:A6:32:8A:65:00 Class: 0x0000041c Jun 17 13:21:47 garage bthelper[713]: Changing power on succeeded Jun 17 13:21:48 garage sudo[828]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:48 garage wireless.js[624]: SETTING APPROPRIATE REG DOMAIN: US Jun 17 13:21:48 garage sudo[839]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jun 17 13:21:48 garage sudo[839]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:48 garage sudo[839]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:48 garage sudo[841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set US Jun 17 13:21:48 garage sudo[841]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:48 garage sudo[841]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:48 garage wireless.js[624]: SUCCESSFULLY SET NEW REGDOMAIN: US Jun 17 13:21:49 garage sudo[848]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 17 13:21:49 garage sudo[848]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:49 garage sudo[848]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:49 garage sudo[850]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jun 17 13:21:49 garage sudo[850]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:49 garage sudo[850]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:49 garage avahi-daemon[623]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Jun 17 13:21:49 garage avahi-daemon[623]: New relevant interface wlan0.IPv4 for mDNS. Jun 17 13:21:49 garage avahi-daemon[623]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Jun 17 13:21:49 garage kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 17 13:21:49 garage systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Jun 17 13:21:49 garage systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Jun 17 13:21:49 garage dnsmasq[856]: dnsmasq: syntax check OK. Jun 17 13:21:49 garage hostapd[857]: Configuration file: /etc/hostapd/hostapd.conf Jun 17 13:21:49 garage hostapd[857]: wlan0: Could not connect to kernel driver Jun 17 13:21:49 garage hostapd[857]: Using interface wlan0 with hwaddr dc:a6:32:8a:64:ff and ssid "Volumio-09933" Jun 17 13:21:49 garage dnsmasq[863]: started, version 2.80 cachesize 150 Jun 17 13:21:49 garage dnsmasq[863]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Jun 17 13:21:49 garage dnsmasq-dhcp[863]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Jun 17 13:21:49 garage dnsmasq[863]: reading /etc/resolv.conf Jun 17 13:21:49 garage dnsmasq[863]: using nameserver 208.67.222.222#53 Jun 17 13:21:49 garage dnsmasq[863]: using nameserver 208.67.220.220#53 Jun 17 13:21:49 garage dnsmasq[863]: read /etc/hosts - 1 addresses Jun 17 13:21:49 garage systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Jun 17 13:21:49 garage systemd[1]: Reached target Host and Network Name Lookups. Jun 17 13:21:49 garage nmbd[715]: [2024/06/17 13:21:49.919687, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 17 13:21:49 garage nmbd[715]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jun 17 13:21:49 garage systemd[1]: Started Samba NMB Daemon. Jun 17 13:21:49 garage hostapd[857]: wlan0: interface state UNINITIALIZED->ENABLED Jun 17 13:21:49 garage hostapd[857]: wlan0: AP-ENABLED Jun 17 13:21:49 garage systemd[1]: Starting Samba Winbind Daemon... Jun 17 13:21:49 garage systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Jun 17 13:21:50 garage iwconfig[873]: Error for wireless request "Set Power Management" (8B2C) : Jun 17 13:21:50 garage iwconfig[873]: SET failed on device wlan0 ; Invalid argument. Jun 17 13:21:50 garage systemd[1]: wireless.service: Succeeded. Jun 17 13:21:50 garage systemd[1]: Started Wireless Services. Jun 17 13:21:50 garage systemd[1]: Started Volumio Backend Module. Jun 17 13:21:50 garage systemd[1]: Started Volumio Cpu Tweaker. Jun 17 13:21:50 garage volumio-cpu-tweak[875]: Setting RT Priority for mpd Jun 17 13:21:50 garage volumio-cpu-tweak[875]: pid 35's current scheduling policy: SCHED_OTHER Jun 17 13:21:50 garage volumio-cpu-tweak[875]: pid 35's current scheduling priority: 0 Jun 17 13:21:50 garage volumio-cpu-tweak[875]: Setting MPD Affinity Jun 17 13:21:50 garage volumio-cpu-tweak[875]: pid 3's current affinity mask: f Jun 17 13:21:50 garage volumio-cpu-tweak[875]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jun 17 13:21:50 garage volumio-cpu-tweak[875]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jun 17 13:21:50 garage systemd[1]: volumio_cpu_tweak.service: Succeeded. Jun 17 13:21:50 garage winbindd[869]: [2024/06/17 13:21:50.434880, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jun 17 13:21:50 garage winbindd[869]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jun 17 13:21:50 garage systemd[1]: Started Samba Winbind Daemon. Jun 17 13:21:50 garage winbindd[869]: [2024/06/17 13:21:50.510503, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 17 13:21:50 garage winbindd[869]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jun 17 13:21:50 garage systemd[1]: Starting Samba SMB Daemon... Jun 17 13:21:50 garage sh[523]: eth0: probing address 10.99.10.123/24 Jun 17 13:21:50 garage dhcpcd[568]: eth0: probing address 10.99.10.123/24 Jun 17 13:21:51 garage ntpd[773]: Listen normally on 3 wlan0 192.168.211.1:123 Jun 17 13:21:51 garage ntpd[773]: new interface(s) found: waking up resolver Jun 17 13:21:51 garage kernel: hwmon hwmon1: Undervoltage detected! Jun 17 13:21:52 garage winbindd[869]: [2024/06/17 13:21:52.213183, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Jun 17 13:21:52 garage winbindd[869]: res_names->count = 3, expected 4 Jun 17 13:21:52 garage systemd[1]: Started Samba SMB Daemon. Jun 17 13:21:52 garage smbd[894]: [2024/06/17 13:21:52.260410, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 17 13:21:52 garage smbd[894]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jun 17 13:21:52 garage systemd[1]: Reached target Multi-User System. Jun 17 13:21:52 garage systemd[1]: Reached target Graphical Interface. Jun 17 13:21:52 garage systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 17 13:21:52 garage systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 17 13:21:52 garage systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 17 13:21:52 garage systemd[1]: Startup finished in 16.168s (kernel) + 18.148s (userspace) = 34.316s. Jun 17 13:21:53 garage volumio[874]: info: ------------------------------------------- Jun 17 13:21:53 garage volumio[874]: info: ----- Volumio3 ---- Jun 17 13:21:53 garage volumio[874]: info: ------------------------------------------- Jun 17 13:21:53 garage volumio[874]: info: ----- System startup ---- Jun 17 13:21:53 garage volumio[874]: info: ------------------------------------------- Jun 17 13:21:54 garage volumio[874]: info: MYVOLUMIO Environment detected Jun 17 13:21:55 garage volumio[874]: info: Plugin folders cleanup Jun 17 13:21:55 garage volumio[874]: info: Scanning into folder /volumio/app/plugins/ Jun 17 13:21:55 garage volumio[874]: info: Scanning category audio_interface Jun 17 13:21:55 garage volumio-remote-updater[618]: [2024-06-17 13:21:55] [connect] Successful connection Jun 17 13:21:55 garage volumio[874]: info: Scanning category miscellanea Jun 17 13:21:55 garage volumio[874]: info: Scanning category music_service Jun 17 13:21:55 garage volumio[874]: info: Scanning category plugins.json Jun 17 13:21:55 garage volumio[874]: info: Scanning category system_controller Jun 17 13:21:55 garage volumio[874]: info: Scanning category user_interface Jun 17 13:21:55 garage volumio[874]: info: Scanning into folder /data/plugins/ Jun 17 13:21:55 garage volumio[874]: info: Scanning category music_service Jun 17 13:21:55 garage volumio[874]: info: Plugin folders cleanup completed Jun 17 13:21:55 garage volumio[874]: info: ------------------------------------------- Jun 17 13:21:55 garage volumio[874]: info: ----- Core plugins startup ---- Jun 17 13:21:55 garage volumio[874]: info: ------------------------------------------- Jun 17 13:21:55 garage volumio[874]: info: Loading plugins from folder /volumio/app/plugins/ Jun 17 13:21:55 garage volumio[874]: info: Adding plugin upnp to MyMusic Plugins Jun 17 13:21:55 garage volumio[874]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 17 13:21:55 garage volumio[874]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 17 13:21:55 garage volumio[874]: info: Loading plugins from folder /data/plugins/ Jun 17 13:21:55 garage volumio[874]: info: Loading plugin "system"... Jun 17 13:21:55 garage volumio[874]: info: Loading plugin "appearance"... Jun 17 13:21:55 garage sh[523]: eth0: leased 10.99.10.123 for 86400 seconds Jun 17 13:21:55 garage dhcpcd[568]: eth0: leased 10.99.10.123 for 86400 seconds Jun 17 13:21:55 garage avahi-daemon[623]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.99.10.123. Jun 17 13:21:55 garage sh[523]: eth0: adding route to 10.99.10.0/24 Jun 17 13:21:55 garage sh[523]: eth0: adding default route via 10.99.10.1 Jun 17 13:21:55 garage avahi-daemon[623]: New relevant interface eth0.IPv4 for mDNS. Jun 17 13:21:55 garage dhcpcd[568]: eth0: adding route to 10.99.10.0/24 Jun 17 13:21:55 garage avahi-daemon[623]: Registering new address record for 10.99.10.123 on eth0.IPv4. Jun 17 13:21:55 garage dhcpcd[568]: eth0: adding default route via 10.99.10.1 Jun 17 13:21:55 garage dnsmasq[863]: reading /etc/resolv.conf Jun 17 13:21:55 garage dnsmasq[863]: using nameserver 10.99.10.20#53 Jun 17 13:21:55 garage dnsmasq[863]: using nameserver 8.8.8.8#53 Jun 17 13:21:55 garage dnsmasq[863]: using nameserver 208.67.222.222#53 Jun 17 13:21:55 garage dnsmasq[863]: using nameserver 208.67.220.220#53 Jun 17 13:21:55 garage sh[523]: forked to background, child pid 937 Jun 17 13:21:55 garage dhcpcd[568]: forked to background, child pid 937 Jun 17 13:21:56 garage ifplugd(eth0)[762]: client: ifup: interface eth0 already configured Jun 17 13:21:56 garage sh[523]: eth0=eth0 Jun 17 13:21:56 garage ifplugd(eth0)[762]: Program executed successfully. Jun 17 13:21:57 garage ntpd[773]: Listen normally on 4 eth0 10.99.10.123:123 Jun 17 13:21:57 garage ntpd[773]: new interface(s) found: waking up resolver Jun 17 13:21:57 garage volumio[874]: info: Loading plugin "network"... Jun 17 13:21:57 garage volumio[874]: info: Refreshing Cached IP Addresses Jun 17 13:21:57 garage sudo[964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 17 13:21:57 garage sudo[964]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:57 garage sudo[964]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:57 garage volumio[874]: info: Loading plugin "services"... Jun 17 13:21:57 garage sudo[966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 17 13:21:57 garage sudo[966]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:57 garage volumio[874]: info: Loading plugin "alsa_controller"... Jun 17 13:21:57 garage sudo[966]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:57 garage sudo[969]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 17 13:21:57 garage sudo[969]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:57 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 17 13:21:57 garage volumio[874]: info: Loading plugin "wizard"... Jun 17 13:21:57 garage volumio[874]: info: Loading plugin "networkfs"... Jun 17 13:21:57 garage volumio[874]: info: Starting Udev Watcher for removable devices Jun 17 13:21:57 garage sudo[975]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=david,password=CSolutions1!,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //10.99.10.8/music /mnt/NAS/Martinez_NAS Jun 17 13:21:57 garage sudo[975]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:21:57 garage volumio[874]: info: Ignoring mount for partition: boot Jun 17 13:21:57 garage volumio[874]: info: Ignoring mount for partition: volumio Jun 17 13:21:57 garage volumio[874]: info: Ignoring mount for partition: volumio_data Jun 17 13:21:57 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 17 13:21:57 garage volumio[874]: info: Loading plugin "volumio_command_line_client"... Jun 17 13:21:57 garage volumio[874]: info: Loading plugin "upnp"... Jun 17 13:21:57 garage volumio[874]: info: [1718655717532] Starting Upmpd Daemon Jun 17 13:21:57 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 17 13:21:57 garage volumio[874]: info: Loading plugin "my_music"... Jun 17 13:21:57 garage volumio[874]: info: Loading plugin "mpd"... Jun 17 13:21:57 garage kernel: Key type cifs.spnego registered Jun 17 13:21:57 garage kernel: Key type cifs.idmap registered Jun 17 13:21:57 garage kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Jun 17 13:21:57 garage kernel: CIFS: Attempting to mount \\10.99.10.8\music Jun 17 13:21:57 garage sudo[975]: pam_unix(sudo:session): session closed for user root Jun 17 13:21:58 garage volumio[874]: info: Loading plugin "upnp_browser"... Jun 17 13:21:58 garage volumio[874]: info: Loading plugin "alarm-clock"... Jun 17 13:21:59 garage volumio[874]: info: Loading plugin "airplay_emulation"... Jun 17 13:21:59 garage volumio[874]: info: Starting Shairport Sync Jun 17 13:21:59 garage volumio[874]: info: Loading plugin "last_100"... Jun 17 13:21:59 garage volumio[874]: info: Loading plugin "webradio"... Jun 17 13:21:59 garage volumio[874]: info: Loading plugin "i2s_dacs"... Jun 17 13:21:59 garage volumio[874]: info: Loading plugin "volumiodiscovery"... Jun 17 13:21:59 garage volumio[874]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 17 13:21:59 garage volumio[874]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 17 13:21:59 garage node[874]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 17 13:21:59 garage volumio[874]: *** WARNING *** For more information see Jun 17 13:21:59 garage volumio[874]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 17 13:21:59 garage volumio[874]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 17 13:21:59 garage volumio[874]: *** WARNING *** For more information see Jun 17 13:21:59 garage node[874]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 17 13:21:59 garage node[874]: *** WARNING *** For more information see Jun 17 13:21:59 garage node[874]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 17 13:21:59 garage node[874]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 17 13:21:59 garage node[874]: *** WARNING *** For more information see Jun 17 13:21:59 garage volumio[874]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 17 13:21:59 garage volumio[874]: info: Discovery: Started advertising with name: Garage Jun 17 13:21:59 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 17 13:21:59 garage volumio[874]: info: Loading plugin "spop"... Jun 17 13:22:01 garage sudo[969]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:01 garage volumio[874]: info: Loading plugin "outputs"... Jun 17 13:22:01 garage volumio[874]: info: Loading plugin "albumart"... Jun 17 13:22:01 garage volumio[874]: info: Plugin example_plugin is not enabled Jun 17 13:22:01 garage volumio[874]: info: Loading plugin "inputs"... Jun 17 13:22:01 garage volumio[874]: info: Loading plugin "updater_comm"... Jun 17 13:22:01 garage volumio[874]: info: Plugin mpdemulation is not enabled Jun 17 13:22:01 garage volumio[874]: info: Loading plugin "rest_api"... Jun 17 13:22:01 garage volumio[874]: info: Loading plugin "websocket"... Jun 17 13:22:01 garage volumio[874]: info: Starting Socket.io Server version 2.3.0 Jun 17 13:22:01 garage volumio[874]: info: Loading i18n strings for locale en Jun 17 13:22:01 garage volumio[874]: Updating browse sources language Jun 17 13:22:01 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 17 13:22:01 garage volumio[874]: Forking 3 albumart workers Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::initPlayerControls Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 17 13:22:02 garage volumio[874]: Express server listening on port 3000 Jun 17 13:22:02 garage volumio[874]: [Metrics] WebUI: 9s 284.11ms Jun 17 13:22:02 garage volumio[874]: info: CoreStateMachine::resetVolumioState Jun 17 13:22:02 garage volumio[874]: info: CoreStateMachine::getcurrentVolume Jun 17 13:22:02 garage volumio[874]: info: CoreCommandRouter::volumioRetrievevolume Jun 17 13:22:03 garage volumio[874]: verbose: New Socket.io Connection to 10.99.10.123:3000 from 10.99.10.118 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 17 13:22:03 garage volumio[874]: verbose: New Socket.io Connection to 10.99.10.123:3000 from 10.99.10.118 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 17 13:22:03 garage volumio[874]: info: CoreStateMachine::pushState Jun 17 13:22:03 garage volumio[874]: info: CorePlayQueue::getTrack 0 Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::volumioPushState Jun 17 13:22:03 garage volumio[874]: info: CoreStateMachine::updateTrackBlock Jun 17 13:22:03 garage volumio[874]: info: CorePlayQueue::getTrackBlock Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::volumioRetrievevolume Jun 17 13:22:03 garage volumio[874]: Starting albumart workers Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 17 13:22:03 garage volumio[874]: info: Reloading queue from file Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Jun 17 13:22:03 garage volumio[874]: info: CoreStateMachine::setRepeat true single undefined Jun 17 13:22:03 garage volumio[874]: info: CoreStateMachine::pushState Jun 17 13:22:03 garage volumio[874]: info: CorePlayQueue::getTrack 0 Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::volumioPushState Jun 17 13:22:03 garage volumio[874]: info: CoreStateMachine::setRandom false Jun 17 13:22:03 garage volumio[874]: info: CoreStateMachine::pushState Jun 17 13:22:03 garage volumio[874]: info: CorePlayQueue::getTrack 0 Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::volumioPushState Jun 17 13:22:03 garage volumio[874]: info: Setting Device type: Raspberry PI Jun 17 13:22:03 garage volumio[874]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jun 17 13:22:03 garage volumio[874]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Jun 17 13:22:03 garage volumio[874]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jun 17 13:22:03 garage volumio[874]: Starting albumart workers Jun 17 13:22:03 garage volumio[874]: Starting albumart workers Jun 17 13:22:03 garage volumio[874]: info: Completed loading Core Plugins Jun 17 13:22:03 garage volumio[874]: info: Preparing to generate the ALSA configuration file Jun 17 13:22:03 garage volumio[874]: info: CoreStateMachine::pushState Jun 17 13:22:03 garage volumio[874]: info: CorePlayQueue::getTrack 0 Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::volumioPushState Jun 17 13:22:03 garage volumio[874]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jun 17 13:22:03 garage volumio[874]: info: Reading ALSA contributions from plugins. Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::volumioGetState Jun 17 13:22:03 garage volumio[874]: info: CorePlayQueue::getTrack 0 Jun 17 13:22:03 garage volumio[874]: info: Asound.conf file written Jun 17 13:22:03 garage sudo[1053]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jun 17 13:22:03 garage sudo[1053]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:03 garage sudo[1053]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:03 garage volumio[874]: info: Output device has changed, restarting MPD Jun 17 13:22:03 garage volumio[874]: info: Output device has changed, restarting Shairport Sync Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 17 13:22:03 garage sudo[1058]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 17 13:22:03 garage sudo[1058]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:03 garage sudo[1058]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:03 garage sudo[1062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 17 13:22:03 garage sudo[1062]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:03 garage volumio[874]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 17 13:22:03 garage volumio[874]: info: ___________ START PLUGINS ___________ Jun 17 13:22:03 garage volumio[874]: info: ControllerMpd::onStart: Initializing MPD Jun 17 13:22:03 garage volumio[874]: info: Creating MPD Configuration file Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 17 13:22:03 garage volumio[874]: info: [1718655723963] CoreMusicLibrary::Adding element Media Servers Jun 17 13:22:03 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 17 13:22:04 garage sudo[1071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 17 13:22:04 garage sudo[1071]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:04 garage sudo[1074]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 17 13:22:04 garage systemd[1]: Listening on mpd.socket. Jun 17 13:22:04 garage sudo[1074]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:04 garage systemd[1]: Starting Music Player Daemon... Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 17 13:22:04 garage sudo[1071]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:04 garage systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jun 17 13:22:04 garage systemd[1]: mpd.service: Succeeded. Jun 17 13:22:04 garage systemd[1]: Stopped Music Player Daemon. Jun 17 13:22:04 garage systemd[1]: Starting Music Player Daemon... Jun 17 13:22:04 garage volumio[874]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 17 13:22:04 garage sudo[1083]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 17 13:22:04 garage sudo[1083]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:04 garage sudo[1083]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jun 17 13:22:04 garage sudo[1083]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:04 garage volumio[874]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 17 13:22:04 garage volumio[874]: info: [1718655724241] CoreMusicLibrary::Adding element Last_100 Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 17 13:22:04 garage volumio[874]: info: [1718655724247] CoreMusicLibrary::Adding element Webradio Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 17 13:22:04 garage volumio[874]: info: Initializing BBC Radios Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: Creating Spotify config file Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: Volumio Calling Home Jun 17 13:22:04 garage volumio[874]: info: Discovery: adding 9e1b2025-021a-49eb-9f93-746b5977a482 Jun 17 13:22:04 garage volumio[874]: info: Discovery: Found device Living Room Jun 17 13:22:04 garage volumio[874]: info: Discovery: Connecting to remote: 10.99.10.119 Jun 17 13:22:04 garage volumio[874]: info: Discovery: adding 3df4b8bb-1980-4269-bccc-04d65e7968d9 Jun 17 13:22:04 garage volumio[874]: info: Discovery: Found device Garage Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::volumioGetState Jun 17 13:22:04 garage volumio[874]: info: CorePlayQueue::getTrack 0 Jun 17 13:22:04 garage volumio[874]: info: Discovery: this is already registered, 3df4b8bb-1980-4269-bccc-04d65e7968d9 Jun 17 13:22:04 garage volumio[874]: info: Discovery: Found device Garage Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::volumioGetState Jun 17 13:22:04 garage volumio[874]: info: CorePlayQueue::getTrack 0 Jun 17 13:22:04 garage volumio[874]: info: MPD Permissions set Jun 17 13:22:04 garage volumio[874]: info: MPD Permissions set Jun 17 13:22:04 garage volumio[874]: info: Spotify config file written Jun 17 13:22:04 garage volumio[874]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage sudo[1121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 17 13:22:04 garage sudo[1121]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 17 13:22:04 garage volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 17 13:22:04 garage systemd[1]: Started go-librespot Daemon. Jun 17 13:22:04 garage go-librespot[1131]: Librespot-go daemon starting... Jun 17 13:22:04 garage sudo[1121]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:04 garage volumio[874]: info: Discovery: Connected to remote: 10.99.10.119 Jun 17 13:22:05 garage volumio[874]: info: Volumio called home Jun 17 13:22:05 garage volumio[874]: info: Starting Shairport Sync Jun 17 13:22:05 garage volumio[874]: info: Starting Shairport Sync Jun 17 13:22:05 garage volumio[874]: info: Starting Shairport Sync Jun 17 13:22:05 garage volumio[874]: info: CoreCommandRouter::volumioGetState Jun 17 13:22:05 garage volumio[874]: info: CorePlayQueue::getTrack 0 Jun 17 13:22:05 garage sudo[1134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 17 13:22:05 garage sudo[1136]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 17 13:22:05 garage sudo[1136]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:05 garage sudo[1134]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:05 garage sudo[1138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 17 13:22:05 garage sudo[1138]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:05 garage systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 17 13:22:05 garage systemd[1]: shairport-sync.service: Succeeded. Jun 17 13:22:05 garage systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 17 13:22:05 garage systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 17 13:22:05 garage sudo[1138]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:05 garage sudo[1136]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:05 garage sudo[1134]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:05 garage volumio[874]: info: Shairport-Sync Started Jun 17 13:22:05 garage volumio[874]: Error adding Membership: Error: addMembership EINVAL Jun 17 13:22:05 garage volumio[874]: info: Shairport-Sync Started Jun 17 13:22:05 garage volumio[874]: info: Shairport-Sync Started Jun 17 13:22:05 garage go-librespot[1131]: time="2024-06-17T13:22:05-07:00" level=info msg="generated new device id: 884788cab5a69a32e9a472f4f095fdb235653a23" Jun 17 13:22:06 garage go-librespot[1131]: time="2024-06-17T13:22:06-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 17 13:22:06 garage go-librespot[1131]: time="2024-06-17T13:22:06-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 17 13:22:06 garage go-librespot[1131]: time="2024-06-17T13:22:06-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 17 13:22:06 garage go-librespot[1131]: time="2024-06-17T13:22:06-07:00" level=debug msg="zeroconf server listening on port 38629" Jun 17 13:22:07 garage sudo[1153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 17 13:22:07 garage sudo[1153]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:07 garage sudo[1153]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:07 garage sudo[1155]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 17 13:22:07 garage sudo[1155]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:07 garage sudo[1155]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:07 garage sudo[1159]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 17 13:22:07 garage sudo[1159]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:22:07 garage systemd[1]: Started UPnP Renderer front-end to MPD. Jun 17 13:22:07 garage sudo[1159]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:07 garage volumio[874]: info: Upmpdcli Daemon Started Jun 17 13:22:08 garage volumio[874]: info: go-librespot daemon successfully initialized Jun 17 13:22:08 garage mpd[1098]: Jun 17 13:22 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 17 13:22:08 garage systemd[1]: Started Music Player Daemon. Jun 17 13:22:08 garage sudo[1062]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:08 garage sudo[1074]: pam_unix(sudo:session): session closed for user root Jun 17 13:22:08 garage volumio[874]: info: Completed starting Core Plugins Jun 17 13:22:08 garage volumio[874]: info: ------------------------------------------- Jun 17 13:22:08 garage volumio[874]: info: ----- MyVolumio plugins startup ---- Jun 17 13:22:08 garage volumio[874]: info: ------------------------------------------- Jun 17 13:22:08 garage volumio[874]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 17 13:22:08 garage volumio[1161]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 17 13:22:08 garage volumio[874]: error: MPD error: The expression evaluated to a falsy value: Jun 17 13:22:08 garage volumio[874]: assert.ok(self.idling) Jun 17 13:22:08 garage volumio[874]: error: The expression evaluated to a falsy value: Jun 17 13:22:08 garage volumio[874]: assert.ok(self.idling) Jun 17 13:22:08 garage volumio[874]: info: MPD running with PID1098 Jun 17 13:22:08 garage volumio[874]: ,establishing connection Jun 17 13:22:08 garage volumio[874]: error: updateQueue error: null Jun 17 13:22:08 garage volumio[874]: error: updateQueue error: null Jun 17 13:22:09 garage go-librespot[1131]: time="2024-06-17T13:22:09-07:00" level=debug msg="obtained new client token: AABWiOt0m7sdBQ8+afXDVUy/q5vstmcFb1aJ3NbVZr60LNdpl4bkjqSvjhq3CW9kmy5rIH5I+H7yedlryYTVEq5LVYnqAtstCYJymyyK5sh6OAoeoQPOeGBy1qlOGU6alNLSsI+K+zhl3PQTRxnZoddlJnX5/il1xK8YFS1D9jxop1XuYFm9duoC99hyZ+jBbJ7nAFINe11a0V2LOFuftBNWmMQVpBSzuoYz8QJZxhkapN12BZ7/yFFHo+QsBijMgg==" Jun 17 13:22:09 garage go-librespot[1131]: time="2024-06-17T13:22:09-07:00" level=debug msg="completed keyexchange" Jun 17 13:22:09 garage systemd[1]: systemd-fsckd.service: Succeeded. Jun 17 13:22:10 garage volumio-remote-updater[618]: [2024-06-17 13:22:10] [connect] Successful connection Jun 17 13:22:10 garage volumio-remote-updater[618]: [2024-06-17 13:22:10] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1718655730 101 Jun 17 13:22:10 garage volumio[874]: 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: 4 Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="completed challenge" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="authenticated as 125982599" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="authenticated as 125982599" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="dealer connection opened" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=info msg="accepted zeroconf user 125982599 from Dave's Pixel" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="received connection id: OWU1NmJjOWMtOTJhYS00NGIzLWFjMGQtNGRkNDY1MjhjM2M2K2RlYWxlcit0Y3A6Ly9ndWMzLWRlYWxlci1hLXI0YnYuZ3VjMy5zcG90aWZ5Lm5ldDo1NzAwKzBEMkJFNEE2ODk2ODkxMjhBQTA5MUQwNzQ3N0VEMzUwREU2REJDNzYyRUEwODk3RDBCMUZBNTM1NENFNTAyMkE=" Jun 17 13:22:10 garage go-librespot[1131]: time="2024-06-17T13:22:10-07:00" level=debug msg="put connect state because NEW_DEVICE" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="handling transfer player command from 3d99c1a58512988ad5277e81c440ae29b6896071" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="loading track spotify:track:0CSZ1DMvRZH0WLB5V0WSom (paused: true, position: 2235678ms)" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=trace msg="emitting websocket event: will_play" Jun 17 13:22:11 garage volumio[874]: info: Initializing connection to go-librespot Websocket Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="new websocket client" Jun 17 13:22:11 garage volumio[874]: info: Connection to go-librespot Websocket established Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:0CSZ1DMvRZH0WLB5V0WSom" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="requested aes key for file 26cc47c131686c6cf886ea09e4d3937e0544467b, gid: 0CSZ1DMvRZH0WLB5V0WSom" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2874" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2011" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="fetched first chunk of 110, total size is 57330240 bytes" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="fetched chunk 3/109, size: 524288" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="fetched chunk 109/109, size: 182848" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="fetched chunk 2/109, size: 524288" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=trace msg="seek to 2235678ms (diff: 977ms, samples: 98593399, bytes: 57208020)" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=debug msg="fetched chunk 1/109, size: 524288" Jun 17 13:22:11 garage go-librespot[1131]: time="2024-06-17T13:22:11-07:00" level=info msg="loaded track \"MX\" (uri: spotify:track:0CSZ1DMvRZH0WLB5V0WSom, paused: true, position: 2235678ms, duration: 2238733ms)" Jun 17 13:22:12 garage go-librespot[1131]: time="2024-06-17T13:22:12-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 17 13:22:12 garage go-librespot[1131]: time="2024-06-17T13:22:12-07:00" level=trace msg="emitting websocket event: metadata" Jun 17 13:22:12 garage go-librespot[1131]: time="2024-06-17T13:22:12-07:00" level=trace msg="emitting websocket event: active" Jun 17 13:22:12 garage go-librespot[1131]: time="2024-06-17T13:22:12-07:00" level=debug msg="sending successful reply for delaer request" Jun 17 13:22:12 garage go-librespot[1131]: time="2024-06-17T13:22:12-07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 17 13:22:12 garage go-librespot[1131]: time="2024-06-17T13:22:12-07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 17 13:22:12 garage go-librespot[1131]: time="2024-06-17T13:22:12-07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 17 13:22:12 garage volumio[874]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0CSZ1DMvRZH0WLB5V0WSom","name":"MX","artist_names":["Deftones"],"album_name":"Around the Fur","album_cover_url":"https://i.scdn.co/image/ab67616d00001e020b1129853982ea17845d4eb6","position":2235678,"duration":2238733,"release_date":"year:1997 month:10 day:27","track_number":10,"disc_number":1}} Jun 17 13:22:12 garage volumio[874]: SPOTIFY: received: {"type":"active","data":null} Jun 17 13:22:12 garage volumio[874]: info: Aligning Spotify Volume to Volumio Volume Jun 17 13:22:12 garage volumio[874]: info: CoreCommandRouter::volumioGetState Jun 17 13:22:12 garage volumio[874]: info: CorePlayQueue::getTrack 0 Jun 17 13:22:12 garage volumio[874]: info: Setting Spotify Volume from Volumio: 100 Jun 17 13:22:12 garage go-librespot[1131]: time="2024-06-17T13:22:12-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 17 13:22:12 garage go-librespot[1131]: time="2024-06-17T13:22:12-07:00" level=trace msg="emitting websocket event: paused" Jun 17 13:22:12 garage volumio[874]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0CSZ1DMvRZH0WLB5V0WSom","play_origin":"unknown"}} Jun 17 13:22:12 garage volumio[874]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 17 13:22:12 garage volumio[874]: TypeError: Cannot read property 'service' of undefined Jun 17 13:22:12 garage volumio[874]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Jun 17 13:22:12 garage volumio[874]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:270:18) Jun 17 13:22:12 garage volumio[874]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Jun 17 13:22:12 garage volumio[874]: at WebSocket.emit (events.js:315:20) Jun 17 13:22:12 garage volumio[874]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Jun 17 13:22:12 garage volumio[874]: at Receiver.emit (events.js:315:20) Jun 17 13:22:12 garage volumio[874]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Jun 17 13:22:12 garage volumio[874]: at internal/process/task_queues.js:149:7 Jun 17 13:22:12 garage volumio[874]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Jun 17 13:22:12 garage volumio[874]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) Jun 17 13:22:12 garage volumio[874]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Jun 17 13:22:12 garage volumio[874]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 17 13:22:12 garage sudo[1191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-06-17 13:21 Jun 17 13:22:12 garage sudo[1191]: 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"