-- Logs begin at Tue 2025-04-22 12:12:53 CDT, end at Tue 2025-04-22 12:13:25 CDT. -- Apr 22 12:12:53 ritsu kernel: Booting Linux on physical CPU 0x0 Apr 22 12:12:53 ritsu kernel: Linux version 6.1.69-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) #1710 SMP Thu Dec 21 13:17:38 GMT 2023 Apr 22 12:12:53 ritsu kernel: CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d Apr 22 12:12:53 ritsu kernel: CPU: div instructions available: patching division code Apr 22 12:12:53 ritsu kernel: CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache Apr 22 12:12:53 ritsu kernel: OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.4 Apr 22 12:12:53 ritsu kernel: random: crng init done Apr 22 12:12:53 ritsu kernel: Memory policy: Data cache writealloc Apr 22 12:12:53 ritsu kernel: Reserved memory: created CMA memory pool at 0x000000002a000000, size 64 MiB Apr 22 12:12:53 ritsu kernel: OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool Apr 22 12:12:53 ritsu kernel: Zone ranges: Apr 22 12:12:53 ritsu kernel: DMA [mem 0x0000000000000000-0x000000002fffffff] Apr 22 12:12:53 ritsu kernel: Normal empty Apr 22 12:12:53 ritsu kernel: HighMem [mem 0x0000000030000000-0x00000000fbffffff] Apr 22 12:12:53 ritsu kernel: Movable zone start for each node Apr 22 12:12:53 ritsu kernel: Early memory node ranges Apr 22 12:12:53 ritsu kernel: node 0: [mem 0x0000000000000000-0x0000000037ffffff] Apr 22 12:12:53 ritsu kernel: node 0: [mem 0x0000000040000000-0x00000000fbffffff] Apr 22 12:12:53 ritsu kernel: Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff] Apr 22 12:12:53 ritsu kernel: percpu: Embedded 17 pages/cpu s37012 r8192 d24428 u69632 Apr 22 12:12:53 ritsu kernel: pcpu-alloc: s37012 r8192 d24428 u69632 alloc=17*4096 Apr 22 12:12:53 ritsu kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Apr 22 12:12:53 ritsu kernel: Built 1 zonelists, mobility grouping on. Total pages: 997696 Apr 22 12:12:53 ritsu 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=1024 bcm2708_fb.fbheight=600 bcm2708_fb.fbswap=1 smsc95xx.macaddr=E4:5F:01:2F:7D:4D 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=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh rootwait bootdelay=5 elevator=noop 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 Apr 22 12:12:53 ritsu kernel: Kernel parameter elevator= does not have any effect anymore. Please use sysfs to set IO scheduler for individual devices. Apr 22 12:12:53 ritsu kernel: Unknown kernel command line parameters "splash imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh bootdelay=5", will be passed to user space. Apr 22 12:12:53 ritsu kernel: Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) Apr 22 12:12:53 ritsu kernel: Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Apr 22 12:12:53 ritsu kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Apr 22 12:12:53 ritsu kernel: software IO TLB: area num 4. Apr 22 12:12:53 ritsu kernel: software IO TLB: mapped [mem 0x0000000023c90000-0x0000000027c90000] (64MB) Apr 22 12:12:53 ritsu kernel: Memory: 3797360K/3997696K available (10240K kernel code, 1505K rwdata, 3388K rodata, 2048K init, 637K bss, 134800K reserved, 65536K cma-reserved, 3211264K highmem) Apr 22 12:12:53 ritsu kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Apr 22 12:12:53 ritsu kernel: ftrace: allocating 37226 entries in 110 pages Apr 22 12:12:53 ritsu kernel: ftrace: allocated 110 pages with 5 groups Apr 22 12:12:53 ritsu kernel: trace event string verifier disabled Apr 22 12:12:53 ritsu kernel: rcu: Hierarchical RCU implementation. Apr 22 12:12:53 ritsu kernel: Rude variant of Tasks RCU enabled. Apr 22 12:12:53 ritsu kernel: Tracing variant of Tasks RCU enabled. Apr 22 12:12:53 ritsu kernel: rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Apr 22 12:12:53 ritsu kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Apr 22 12:12:53 ritsu kernel: GIC: Using split EOI/Deactivate mode Apr 22 12:12:53 ritsu kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Apr 22 12:12:53 ritsu kernel: arch_timer: cp15 timer(s) running at 54.00MHz (phys). Apr 22 12:12:53 ritsu kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns Apr 22 12:12:53 ritsu kernel: sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns Apr 22 12:12:53 ritsu kernel: Switching to timer-based delay loop, resolution 18ns Apr 22 12:12:53 ritsu kernel: Console: colour dummy device 80x30 Apr 22 12:12:53 ritsu kernel: printk: console [tty1] enabled Apr 22 12:12:53 ritsu kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000) Apr 22 12:12:53 ritsu kernel: CPU: Testing write buffer coherency: ok Apr 22 12:12:53 ritsu kernel: CPU0: Spectre BHB: enabling loop workaround for all CPUs Apr 22 12:12:53 ritsu kernel: pid_max: default: 32768 minimum: 301 Apr 22 12:12:53 ritsu kernel: LSM: Security Framework initializing Apr 22 12:12:53 ritsu kernel: Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Apr 22 12:12:53 ritsu kernel: Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Apr 22 12:12:53 ritsu kernel: cgroup: Disabling memory control group subsystem Apr 22 12:12:53 ritsu kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Apr 22 12:12:53 ritsu kernel: cblist_init_generic: Setting adjustable number of callback queues. Apr 22 12:12:53 ritsu kernel: cblist_init_generic: Setting shift to 2 and lim to 1. Apr 22 12:12:53 ritsu kernel: cblist_init_generic: Setting adjustable number of callback queues. Apr 22 12:12:53 ritsu kernel: cblist_init_generic: Setting shift to 2 and lim to 1. Apr 22 12:12:53 ritsu kernel: Setting up static identity map for 0x200000 - 0x20003c Apr 22 12:12:53 ritsu kernel: rcu: Hierarchical SRCU implementation. Apr 22 12:12:53 ritsu kernel: rcu: Max phase no-delay instances is 1000. Apr 22 12:12:53 ritsu kernel: smp: Bringing up secondary CPUs ... Apr 22 12:12:53 ritsu kernel: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Apr 22 12:12:53 ritsu kernel: CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Apr 22 12:12:53 ritsu kernel: CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Apr 22 12:12:53 ritsu kernel: smp: Brought up 1 node, 4 CPUs Apr 22 12:12:53 ritsu kernel: SMP: Total of 4 processors activated (432.00 BogoMIPS). Apr 22 12:12:53 ritsu kernel: CPU: All CPU(s) started in HYP mode. Apr 22 12:12:53 ritsu kernel: CPU: Virtualization extensions available. Apr 22 12:12:53 ritsu kernel: devtmpfs: initialized Apr 22 12:12:53 ritsu kernel: VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0 Apr 22 12:12:53 ritsu kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Apr 22 12:12:53 ritsu kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Apr 22 12:12:53 ritsu kernel: pinctrl core: initialized pinctrl subsystem Apr 22 12:12:53 ritsu kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Apr 22 12:12:53 ritsu kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Apr 22 12:12:53 ritsu kernel: audit: initializing netlink subsys (disabled) Apr 22 12:12:53 ritsu kernel: audit: type=2000 audit(0.020:1): state=initialized audit_enabled=0 res=1 Apr 22 12:12:53 ritsu kernel: thermal_sys: Registered thermal governor 'step_wise' Apr 22 12:12:53 ritsu kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Apr 22 12:12:53 ritsu kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Apr 22 12:12:53 ritsu kernel: Serial: AMBA PL011 UART driver Apr 22 12:12:53 ritsu kernel: bcm2835-mbox fe00b880.mailbox: mailbox enabled Apr 22 12:12:53 ritsu kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2023-10-17T15:39:16, variant start Apr 22 12:12:53 ritsu kernel: raspberrypi-firmware soc:firmware: Firmware hash is 30f0c5e4d076da3ab4f341d88e7d505760b93ad7 Apr 22 12:12:53 ritsu kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Apr 22 12:12:53 ritsu kernel: bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 Apr 22 12:12:53 ritsu kernel: SCSI subsystem initialized Apr 22 12:12:53 ritsu kernel: usbcore: registered new interface driver usbfs Apr 22 12:12:53 ritsu kernel: usbcore: registered new interface driver hub Apr 22 12:12:53 ritsu kernel: usbcore: registered new device driver usb Apr 22 12:12:53 ritsu kernel: usb_phy_generic phy: supply vcc not found, using dummy regulator Apr 22 12:12:53 ritsu kernel: pps_core: LinuxPPS API ver. 1 registered Apr 22 12:12:53 ritsu kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti Apr 22 12:12:53 ritsu kernel: PTP clock support registered Apr 22 12:12:53 ritsu kernel: vgaarb: loaded Apr 22 12:12:53 ritsu kernel: clocksource: Switched to clocksource arch_sys_counter Apr 22 12:12:53 ritsu kernel: VFS: Disk quotas dquot_6.6.0 Apr 22 12:12:53 ritsu kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Apr 22 12:12:53 ritsu kernel: FS-Cache: Loaded Apr 22 12:12:53 ritsu kernel: CacheFiles: Loaded Apr 22 12:12:53 ritsu kernel: NET: Registered PF_INET protocol family Apr 22 12:12:53 ritsu kernel: IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) Apr 22 12:12:53 ritsu kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear) Apr 22 12:12:53 ritsu kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Apr 22 12:12:53 ritsu kernel: TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) Apr 22 12:12:53 ritsu kernel: TCP bind hash table entries: 8192 (order: 5, 131072 bytes, linear) Apr 22 12:12:53 ritsu kernel: TCP: Hash tables configured (established 8192 bind 8192) Apr 22 12:12:53 ritsu kernel: UDP hash table entries: 512 (order: 2, 16384 bytes, linear) Apr 22 12:12:53 ritsu kernel: UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) Apr 22 12:12:53 ritsu kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Apr 22 12:12:53 ritsu kernel: RPC: Registered named UNIX socket transport module. Apr 22 12:12:53 ritsu kernel: RPC: Registered udp transport module. Apr 22 12:12:53 ritsu kernel: RPC: Registered tcp transport module. Apr 22 12:12:53 ritsu kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Apr 22 12:12:53 ritsu kernel: PCI: CLS 0 bytes, default 64 Apr 22 12:12:53 ritsu kernel: Trying to unpack rootfs image as initramfs... Apr 22 12:12:53 ritsu kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available Apr 22 12:12:53 ritsu kernel: Initialise system trusted keyrings Apr 22 12:12:53 ritsu kernel: workingset: timestamp_bits=14 max_order=20 bucket_order=6 Apr 22 12:12:53 ritsu kernel: zbud: loaded Apr 22 12:12:53 ritsu kernel: NFS: Registering the id_resolver key type Apr 22 12:12:53 ritsu kernel: Key type id_resolver registered Apr 22 12:12:53 ritsu kernel: Key type id_legacy registered Apr 22 12:12:53 ritsu kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Apr 22 12:12:53 ritsu kernel: nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Apr 22 12:12:53 ritsu kernel: Key type asymmetric registered Apr 22 12:12:53 ritsu kernel: Asymmetric key parser 'x509' registered Apr 22 12:12:53 ritsu kernel: bounce: pool size: 64 pages Apr 22 12:12:53 ritsu kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) Apr 22 12:12:53 ritsu kernel: io scheduler mq-deadline registered Apr 22 12:12:53 ritsu kernel: io scheduler kyber registered Apr 22 12:12:53 ritsu kernel: brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: Apr 22 12:12:53 ritsu kernel: brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] Apr 22 12:12:53 ritsu kernel: brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 Apr 22 12:12:53 ritsu kernel: brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00ffffffff -> 0x0400000000 Apr 22 12:12:53 ritsu kernel: brcm-pcie fd500000.pcie: setting SCB_ACCESS_EN, READ_UR_MODE, MAX_BURST_SIZE Apr 22 12:12:53 ritsu kernel: brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 Apr 22 12:12:53 ritsu kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Apr 22 12:12:53 ritsu kernel: pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) Apr 22 12:12:53 ritsu kernel: pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 Apr 22 12:12:53 ritsu kernel: pci 0000:00:00.0: PME# supported from D0 D3hot Apr 22 12:12:53 ritsu kernel: PCI: bus0: Fast back to back transfers disabled Apr 22 12:12:53 ritsu kernel: pci_bus 0000:01: supply vpcie3v3 not found, using dummy regulator Apr 22 12:12:53 ritsu kernel: pci_bus 0000:01: supply vpcie3v3aux not found, using dummy regulator Apr 22 12:12:53 ritsu kernel: pci_bus 0000:01: supply vpcie12v not found, using dummy regulator Apr 22 12:12:53 ritsu kernel: brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) Apr 22 12:12:53 ritsu kernel: pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 Apr 22 12:12:53 ritsu kernel: pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] Apr 22 12:12:53 ritsu kernel: pci 0000:01:00.0: PME# supported from D0 D3hot Apr 22 12:12:53 ritsu kernel: PCI: bus1: Fast back to back transfers disabled Apr 22 12:12:53 ritsu kernel: pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] Apr 22 12:12:53 ritsu kernel: pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] Apr 22 12:12:53 ritsu kernel: pci 0000:00:00.0: PCI bridge to [bus 01] Apr 22 12:12:53 ritsu kernel: pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] Apr 22 12:12:53 ritsu kernel: pcieport 0000:00:00.0: enabling device (0000 -> 0002) Apr 22 12:12:53 ritsu kernel: pcieport 0000:00:00.0: PME: Signaling with IRQ 45 Apr 22 12:12:53 ritsu kernel: bcm2708_fb soc:fb: FB found 1 display(s) Apr 22 12:12:53 ritsu kernel: Console: switching to colour frame buffer device 128x37 Apr 22 12:12:53 ritsu kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 1024x600 Apr 22 12:12:53 ritsu kernel: iproc-rng200 fe104000.rng: hwrng registered Apr 22 12:12:53 ritsu kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Apr 22 12:12:53 ritsu kernel: brd: module loaded Apr 22 12:12:53 ritsu kernel: loop: module loaded Apr 22 12:12:53 ritsu kernel: Loading iSCSI transport class v2.0-870. Apr 22 12:12:53 ritsu kernel: bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 Apr 22 12:12:53 ritsu kernel: Freeing initrd memory: 13656K Apr 22 12:12:53 ritsu kernel: unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus Apr 22 12:12:53 ritsu kernel: usbcore: registered new device driver r8152-cfgselector Apr 22 12:12:53 ritsu kernel: usbcore: registered new interface driver r8152 Apr 22 12:12:53 ritsu kernel: usbcore: registered new interface driver lan78xx Apr 22 12:12:53 ritsu kernel: usbcore: registered new interface driver smsc95xx Apr 22 12:12:53 ritsu kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Apr 22 12:12:53 ritsu kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 Apr 22 12:12:53 ritsu kernel: xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0f00040000000890 Apr 22 12:12:53 ritsu kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Apr 22 12:12:53 ritsu kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Apr 22 12:12:53 ritsu kernel: xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Apr 22 12:12:53 ritsu kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.01 Apr 22 12:12:53 ritsu kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Apr 22 12:12:53 ritsu kernel: usb usb1: Product: xHCI Host Controller Apr 22 12:12:53 ritsu kernel: usb usb1: Manufacturer: Linux 6.1.69-v7l+ xhci-hcd Apr 22 12:12:53 ritsu kernel: usb usb1: SerialNumber: 0000:01:00.0 Apr 22 12:12:53 ritsu kernel: hub 1-0:1.0: USB hub found Apr 22 12:12:53 ritsu kernel: hub 1-0:1.0: 1 port detected Apr 22 12:12:53 ritsu kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.01 Apr 22 12:12:53 ritsu kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Apr 22 12:12:53 ritsu kernel: usb usb2: Product: xHCI Host Controller Apr 22 12:12:53 ritsu kernel: usb usb2: Manufacturer: Linux 6.1.69-v7l+ xhci-hcd Apr 22 12:12:53 ritsu kernel: usb usb2: SerialNumber: 0000:01:00.0 Apr 22 12:12:53 ritsu kernel: hub 2-0:1.0: USB hub found Apr 22 12:12:53 ritsu kernel: hub 2-0:1.0: 4 ports detected Apr 22 12:12:53 ritsu kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Apr 22 12:12:53 ritsu kernel: dwc_otg: FIQ enabled Apr 22 12:12:53 ritsu kernel: dwc_otg: NAK holdoff enabled Apr 22 12:12:53 ritsu kernel: dwc_otg: FIQ split-transaction FSM enabled Apr 22 12:12:53 ritsu kernel: Module dwc_common_port init Apr 22 12:12:53 ritsu kernel: usbcore: registered new interface driver uas Apr 22 12:12:53 ritsu kernel: usbcore: registered new interface driver usb-storage Apr 22 12:12:53 ritsu kernel: mousedev: PS/2 mouse device common for all mice Apr 22 12:12:53 ritsu kernel: sdhci: Secure Digital Host Controller Interface driver Apr 22 12:12:53 ritsu kernel: sdhci: Copyright(c) Pierre Ossman Apr 22 12:12:53 ritsu kernel: sdhci-pltfm: SDHCI platform and OF driver helper Apr 22 12:12:53 ritsu kernel: ledtrig-cpu: registered to indicate activity on CPUs Apr 22 12:12:53 ritsu kernel: hid: raw HID events driver (C) Jiri Kosina Apr 22 12:12:53 ritsu kernel: usbcore: registered new interface driver usbhid Apr 22 12:12:53 ritsu kernel: usbhid: USB HID core driver Apr 22 12:12:53 ritsu kernel: Initializing XFRM netlink socket Apr 22 12:12:53 ritsu kernel: NET: Registered PF_PACKET protocol family Apr 22 12:12:53 ritsu kernel: Key type dns_resolver registered Apr 22 12:12:53 ritsu kernel: Registering SWP/SWPB emulation handler Apr 22 12:12:53 ritsu kernel: registered taskstats version 1 Apr 22 12:12:53 ritsu kernel: Loading compiled-in X.509 certificates Apr 22 12:12:53 ritsu kernel: Key type .fscrypt registered Apr 22 12:12:53 ritsu kernel: Key type fscrypt-provisioning registered Apr 22 12:12:53 ritsu kernel: uart-pl011 fe201000.serial: there is not valid maps for state default Apr 22 12:12:53 ritsu kernel: uart-pl011 fe201000.serial: cts_event_workaround enabled Apr 22 12:12:53 ritsu kernel: fe201000.serial: ttyAMA1 at MMIO 0xfe201000 (irq = 51, base_baud = 0) is a PL011 rev2 Apr 22 12:12:53 ritsu kernel: serial serial0: tty port ttyAMA1 registered Apr 22 12:12:53 ritsu kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Apr 22 12:12:53 ritsu kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Apr 22 12:12:53 ritsu kernel: of_cfs_init Apr 22 12:12:53 ritsu kernel: of_cfs_init: OK Apr 22 12:12:53 ritsu kernel: mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA Apr 22 12:12:53 ritsu kernel: Freeing unused kernel image (initmem) memory: 2048K Apr 22 12:12:53 ritsu kernel: Run /init as init process Apr 22 12:12:53 ritsu kernel: with arguments: Apr 22 12:12:53 ritsu kernel: /init Apr 22 12:12:53 ritsu kernel: splash Apr 22 12:12:53 ritsu kernel: with environment: Apr 22 12:12:53 ritsu kernel: HOME=/ Apr 22 12:12:53 ritsu kernel: TERM=linux Apr 22 12:12:53 ritsu kernel: imgpart=/dev/mmcblk0p2 Apr 22 12:12:53 ritsu kernel: imgfile=/volumio_current.sqsh Apr 22 12:12:53 ritsu kernel: bootdelay=5 Apr 22 12:12:53 ritsu kernel: mmc0: new ultra high speed DDR50 SDXC card at address 59b4 Apr 22 12:12:53 ritsu kernel: mmcblk0: mmc0:59b4 USD00 118 GiB Apr 22 12:12:53 ritsu kernel: mmcblk0: p1 p2 p3 Apr 22 12:12:53 ritsu kernel: mmcblk0: mmc0:59b4 USD00 118 GiB Apr 22 12:12:53 ritsu kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd Apr 22 12:12:53 ritsu initramfs: Booting Volumio for BCM2711 Apr 22 12:12:53 ritsu initramfs: This script mounts rootfs RO with an overlay RW layer. Apr 22 12:12:53 ritsu kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Apr 22 12:12:53 ritsu initramfs: IMGPART=/dev/mmcblk0p2 Apr 22 12:12:53 ritsu initramfs: IMGFILE=/volumio_current.sqsh Apr 22 12:12:53 ritsu initramfs: Boot delay (except first time) will be 5 seconds Apr 22 12:12:53 ritsu initramfs: /dev/mmcblk0p2: Apr 22 12:12:53 ritsu kernel: usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 Apr 22 12:12:53 ritsu kernel: usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Apr 22 12:12:53 ritsu kernel: usb 1-1: Product: USB2.0 Hub Apr 22 12:12:53 ritsu kernel: hub 1-1:1.0: USB hub found Apr 22 12:12:53 ritsu kernel: hub 1-1:1.0: 4 ports detected Apr 22 12:12:53 ritsu kernel: EXT4-fs (mmcblk0p2): recovery complete Apr 22 12:12:53 ritsu kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none. Apr 22 12:12:53 ritsu initramfs: Doing a 5 second delay here to give kernel load a headstart Apr 22 12:12:53 ritsu kernel: usb 1-1.2: new full-speed USB device number 3 using xhci_hcd Apr 22 12:12:53 ritsu kernel: usb 1-1.2: New USB device found, idVendor=222a, idProduct=0001, bcdDevice= 0.02 Apr 22 12:12:53 ritsu kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 22 12:12:53 ritsu kernel: usb 1-1.2: Product: ILITEK-TOUCH Apr 22 12:12:53 ritsu kernel: usb 1-1.2: Manufacturer: ILITEK Apr 22 12:12:53 ritsu kernel: input: ILITEK ILITEK-TOUCH Touchscreen as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2:1.0/0003:222A:0001.0001/input/input0 Apr 22 12:12:53 ritsu kernel: hid-generic 0003:222A:0001.0001: input,hiddev96,hidraw0: USB HID v1.10 Device [ILITEK ILITEK-TOUCH] on usb-0000:01:00.0-1.2/input0 Apr 22 12:12:53 ritsu initramfs: Checking for USB updates Apr 22 12:12:53 ritsu initramfs: No USB device detected (when incorrect, try adding 'bootdelay=5' to your boot cmdline) Apr 22 12:12:53 ritsu kernel: loop0: detected capacity change from 0 to 976664 Apr 22 12:12:53 ritsu kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Apr 22 12:12:53 ritsu kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Apr 22 12:12:53 ritsu kernel: EXT4-fs (mmcblk0p3): 2 orphan inodes deleted Apr 22 12:12:53 ritsu kernel: EXT4-fs (mmcblk0p3): recovery complete Apr 22 12:12:53 ritsu kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Quota mode: none. Apr 22 12:12:53 ritsu initramfs: With Option: Apr 22 12:12:53 ritsu initramfs: VOLUMIO_VERSION="3.661" Apr 22 12:12:53 ritsu initramfs: Finish initramfs, continue booting Volumio Apr 22 12:12:53 ritsu systemd[1]: System time before build time, advancing clock. Apr 22 12:12:53 ritsu kernel: NET: Registered PF_INET6 protocol family Apr 22 12:12:53 ritsu kernel: Segment Routing with IPv6 Apr 22 12:12:53 ritsu kernel: In-situ OAM (IOAM) with IPv6 Apr 22 12:12:53 ritsu 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) Apr 22 12:12:53 ritsu systemd[1]: Detected architecture arm. Apr 22 12:12:53 ritsu systemd[1]: Set hostname to . Apr 22 12:12:53 ritsu 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. Apr 22 12:12:53 ritsu systemd[1]: Listening on udev Control Socket. Apr 22 12:12:53 ritsu systemd[1]: Listening on RPCbind Server Activation Socket. Apr 22 12:12:53 ritsu systemd[1]: Listening on fsck to fsckd communication Socket. Apr 22 12:12:53 ritsu systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. Apr 22 12:12:53 ritsu systemd[1]: Created slice User and Session Slice. Apr 22 12:12:53 ritsu systemd[1]: Reached target Slices. Apr 22 12:12:53 ritsu kernel: i2c_dev: i2c /dev entries driver Apr 22 12:12:53 ritsu systemd-journald[212]: Journal started Apr 22 12:12:53 ritsu systemd-journald[212]: Runtime journal (/run/log/journal/32836d460d421189c56ead0a6628f62c) is 3.7M, max 30.0M, 26.2M free. Apr 22 12:12:53 ritsu systemd-modules-load[211]: Inserted module 'i2c_dev' Apr 22 12:12:53 ritsu fake-hwclock[200]: Tue Apr 22 17:12:53 UTC 2025 Apr 22 12:12:53 ritsu systemd[1]: dynamicswap.service: Succeeded. Apr 22 12:12:53 ritsu systemd[1]: Started udev Coldplug all Devices. Apr 22 12:12:53 ritsu systemd[1]: Starting Helper to synchronize boot up for ifupdown... Apr 22 12:12:53 ritsu systemd[1]: Started Helper to synchronize boot up for ifupdown. Apr 22 12:12:53 ritsu systemd[1]: Started Create Static Device Nodes in /dev. Apr 22 12:12:53 ritsu systemd[1]: Starting udev Kernel Device Manager... Apr 22 12:12:53 ritsu systemd[1]: Reached target Local File Systems (Pre). Apr 22 12:12:53 ritsu systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Apr 22 12:12:53 ritsu systemd[1]: Mounting /var/log... Apr 22 12:12:53 ritsu systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Apr 22 12:12:53 ritsu systemd[1]: Mounting /tmp... Apr 22 12:12:53 ritsu systemd[1]: Mounting /var/spool/cups... Apr 22 12:12:53 ritsu systemd[1]: Mounted /var/log. Apr 22 12:12:53 ritsu systemd[1]: Starting Flush Journal to Persistent Storage... Apr 22 12:12:53 ritsu systemd[1]: Mounted /tmp. Apr 22 12:12:53 ritsu systemd[1]: Mounted /var/spool/cups. Apr 22 12:12:53 ritsu systemd[1]: Mounting /var/spool/cups/tmp... Apr 22 12:12:53 ritsu systemd-udevd[232]: Network interface NamePolicy= disabled on kernel command line, ignoring. Apr 22 12:12:53 ritsu systemd[1]: Mounted /var/spool/cups/tmp. Apr 22 12:12:53 ritsu systemd-journald[212]: Runtime journal (/run/log/journal/32836d460d421189c56ead0a6628f62c) is 3.7M, max 30.0M, 26.2M free. Apr 22 12:12:53 ritsu systemd[1]: Started Flush Journal to Persistent Storage. Apr 22 12:12:53 ritsu systemd[1]: Started udev Kernel Device Manager. Apr 22 12:12:53 ritsu systemd[1]: Starting Show Plymouth Boot Screen... Apr 22 12:12:53 ritsu systemd[1]: Received SIGRTMIN+20 from PID 251 (plymouthd). Apr 22 12:12:53 ritsu systemd[1]: Started Show Plymouth Boot Screen. Apr 22 12:12:53 ritsu systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Apr 22 12:12:53 ritsu systemd[1]: Reached target Paths. Apr 22 12:12:53 ritsu systemd[1]: Reached target Local Encrypted Volumes. Apr 22 12:12:53 ritsu systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Apr 22 12:12:53 ritsu systemd-udevd[252]: Using default interface naming scheme 'v240'. Apr 22 12:12:53 ritsu kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Apr 22 12:12:53 ritsu kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Apr 22 12:12:53 ritsu kernel: [vc_sm_connected_init]: start Apr 22 12:12:53 ritsu kernel: [vc_sm_connected_init]: installed successfully Apr 22 12:12:53 ritsu kernel: mc: Linux media interface: v0.10 Apr 22 12:12:53 ritsu systemd-udevd[252]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 22 12:12:54 ritsu kernel: rpi-gpiomem fe200000.gpiomem: window base 0xfe200000 size 0x00001000 Apr 22 12:12:54 ritsu kernel: rpi-gpiomem fe200000.gpiomem: initialised 1 regions as /dev/gpiomem Apr 22 12:12:54 ritsu kernel: videodev: Linux video capture interface: v2.00 Apr 22 12:12:54 ritsu kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Apr 22 12:12:54 ritsu kernel: input: ILITEK ILITEK-TOUCH as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2:1.0/0003:222A:0001.0001/input/input2 Apr 22 12:12:54 ritsu kernel: hid-multitouch 0003:222A:0001.0001: input,hiddev96,hidraw0: USB HID v1.10 Device [ILITEK ILITEK-TOUCH] on usb-0000:01:00.0-1.2/input0 Apr 22 12:12:54 ritsu kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Apr 22 12:12:54 ritsu kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Apr 22 12:12:54 ritsu kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Apr 22 12:12:54 ritsu kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Apr 22 12:12:54 ritsu kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Apr 22 12:12:54 ritsu kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Apr 22 12:12:54 ritsu kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Apr 22 12:12:54 ritsu kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Apr 22 12:12:54 ritsu systemd-udevd[274]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 22 12:12:54 ritsu kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. Apr 22 12:12:54 ritsu kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Apr 22 12:12:54 ritsu kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Apr 22 12:12:54 ritsu kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Apr 22 12:12:54 ritsu kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Apr 22 12:12:54 ritsu kernel: Bluetooth: Core ver 2.22 Apr 22 12:12:54 ritsu kernel: NET: Registered PF_BLUETOOTH protocol family Apr 22 12:12:54 ritsu kernel: Bluetooth: HCI device and connection manager initialized Apr 22 12:12:54 ritsu kernel: Bluetooth: HCI socket layer initialized Apr 22 12:12:54 ritsu kernel: Bluetooth: L2CAP socket layer initialized Apr 22 12:12:54 ritsu kernel: Bluetooth: SCO socket layer initialized Apr 22 12:12:54 ritsu kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Apr 22 12:12:54 ritsu kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Apr 22 12:12:54 ritsu kernel: rpivid feb10000.codec: Device registered as /dev/video19 Apr 22 12:12:54 ritsu kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Apr 22 12:12:54 ritsu kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Apr 22 12:12:54 ritsu kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Apr 22 12:12:54 ritsu kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Apr 22 12:12:55 ritsu systemd[1]: Found device /dev/mmcblk0p1. Apr 22 12:12:55 ritsu kernel: Bluetooth: HCI UART driver ver 2.3 Apr 22 12:12:55 ritsu kernel: Bluetooth: HCI UART protocol H4 registered Apr 22 12:12:55 ritsu kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Apr 22 12:12:55 ritsu kernel: Bluetooth: HCI UART protocol Broadcom registered Apr 22 12:12:55 ritsu kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Apr 22 12:12:55 ritsu kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Apr 22 12:12:55 ritsu kernel: uart-pl011 fe201000.serial: no DMA platform data Apr 22 12:12:55 ritsu kernel: wm8804 1-003b: revision E Apr 22 12:12:55 ritsu kernel: Bluetooth: hci0: BCM: chip id 107 Apr 22 12:12:55 ritsu kernel: Bluetooth: hci0: BCM: features 0x2f Apr 22 12:12:55 ritsu kernel: Bluetooth: hci0: BCM4345C0 Apr 22 12:12:55 ritsu kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Apr 22 12:12:55 ritsu kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Apr 22 12:12:55 ritsu systemd-udevd[246]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 22 12:12:56 ritsu systemd-udevd[267]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 22 12:12:56 ritsu systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Apr 22 12:12:56 ritsu kernel: Bluetooth: hci0: BCM: features 0x2f Apr 22 12:12:56 ritsu kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Apr 22 12:12:56 ritsu kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Apr 22 12:12:56 ritsu systemd[1]: Created slice system-bthelper.slice. Apr 22 12:12:56 ritsu systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Apr 22 12:12:56 ritsu systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Apr 22 12:12:56 ritsu systemd[1]: Condition check resulted in FUSE Control File System being skipped. Apr 22 12:12:56 ritsu systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Apr 22 12:12:56 ritsu systemd[1]: Condition check resulted in Huge Pages File System being skipped. Apr 22 12:12:56 ritsu systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Apr 22 12:12:56 ritsu systemd[1]: Starting File System Check on /dev/mmcblk0p1... Apr 22 12:12:56 ritsu systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 22 12:12:56 ritsu systemd[1]: Started File System Check Daemon to report status. Apr 22 12:12:56 ritsu systemd[1]: Started Load/Save RF Kill Switch Status. Apr 22 12:12:56 ritsu systemd-fsck[388]: fsck.fat 4.1 (2017-01-24) Apr 22 12:12:56 ritsu systemd-fsck[388]: 0x25: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Apr 22 12:12:56 ritsu systemd-fsck[388]: Automatically removing dirty bit. Apr 22 12:12:56 ritsu systemd-fsck[388]: Performing changes. Apr 22 12:12:56 ritsu systemd-fsck[388]: /dev/mmcblk0p1: 366 files, 33362/46774 clusters Apr 22 12:12:56 ritsu systemd[1]: Started File System Check on /dev/mmcblk0p1. Apr 22 12:12:56 ritsu systemd[1]: Mounting /boot... Apr 22 12:12:56 ritsu systemd[1]: Mounted /boot. Apr 22 12:12:56 ritsu systemd[1]: Reached target Local File Systems. Apr 22 12:12:56 ritsu systemd[1]: Started ifup for eth0. Apr 22 12:12:56 ritsu systemd[1]: Starting Raise network interfaces... Apr 22 12:12:56 ritsu systemd[1]: Starting Preprocess NFS configuration... Apr 22 12:12:56 ritsu systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Apr 22 12:12:56 ritsu systemd[1]: Starting Create Volatile Files and Directories... Apr 22 12:12:56 ritsu systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Apr 22 12:12:56 ritsu systemd[1]: Received SIGRTMIN+20 from PID 251 (plymouthd). Apr 22 12:12:56 ritsu systemd[1]: plymouth-read-write.service: Succeeded. Apr 22 12:12:56 ritsu systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Apr 22 12:12:56 ritsu systemd[1]: nfs-config.service: Succeeded. Apr 22 12:12:56 ritsu systemd[1]: Started Preprocess NFS configuration. Apr 22 12:12:56 ritsu systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Apr 22 12:12:56 ritsu systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Apr 22 12:12:56 ritsu systemd[1]: Reached target NFS client services. Apr 22 12:12:56 ritsu systemd[1]: Started Create Volatile Files and Directories. Apr 22 12:12:56 ritsu systemd[1]: Starting RPC bind portmap service... Apr 22 12:12:56 ritsu systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Apr 22 12:12:56 ritsu systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Apr 22 12:12:57 ritsu systemd[1]: Starting Update UTMP about System Boot/Shutdown... Apr 22 12:12:57 ritsu kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Apr 22 12:12:57 ritsu kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Apr 22 12:12:57 ritsu kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Apr 22 12:12:57 ritsu kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Apr 22 12:12:57 ritsu systemd[1]: Started Update UTMP about System Boot/Shutdown. Apr 22 12:12:57 ritsu systemd[1]: Reached target System Initialization. Apr 22 12:12:57 ritsu systemd[1]: Listening on D-Bus System Message Bus Socket. Apr 22 12:12:57 ritsu systemd[1]: Listening on triggerhappy.socket. Apr 22 12:12:57 ritsu ifup[395]: command failed: No such device (-19) Apr 22 12:12:57 ritsu systemd[1]: Started Daily apt download activities. Apr 22 12:12:57 ritsu systemd[1]: Started Daily apt upgrade and clean activities. Apr 22 12:12:57 ritsu sh[394]: command failed: No such device (-19) Apr 22 12:12:57 ritsu systemd[1]: Started Volumio Splash. Apr 22 12:12:57 ritsu systemd[432]: volumiosplash.service: Failed to execute command: No such file or directory Apr 22 12:12:57 ritsu systemd[432]: volumiosplash.service: Failed at step EXEC spawning /bin/volumiosplash.sh: No such file or directory Apr 22 12:12:57 ritsu systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Apr 22 12:12:57 ritsu systemd[1]: Reached target Sockets. Apr 22 12:12:57 ritsu systemd[1]: Reached target Basic System. Apr 22 12:12:57 ritsu systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Apr 22 12:12:57 ritsu systemd[1]: Starting dhcpcd on all interfaces... Apr 22 12:12:57 ritsu systemd[1]: Started D-Bus System Message Bus. Apr 22 12:12:57 ritsu systemd[1]: Started Volumio Log Rotation Service. Apr 22 12:12:57 ritsu systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Apr 22 12:12:57 ritsu systemd[1]: Reached target Login Prompts. Apr 22 12:12:57 ritsu dhcpcd[447]: Not running dhcpcd because /etc/network/interfaces Apr 22 12:12:57 ritsu dhcpcd[447]: defines some interfaces that will use a Apr 22 12:12:57 ritsu dhcpcd[447]: DHCP client or static address Apr 22 12:12:57 ritsu systemd[1]: Starting Login Service... Apr 22 12:12:57 ritsu systemd[1]: Started Manage Sound Card State (restore and store). Apr 22 12:12:57 ritsu systemd[1]: Started Volumio Iptables Module. Apr 22 12:12:57 ritsu alsactl[463]: alsactl 1.1.8 daemon started Apr 22 12:12:57 ritsu systemd[1]: Starting Wireless Services... Apr 22 12:12:57 ritsu systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Apr 22 12:12:57 ritsu systemd[1]: Starting WPA supplicant... Apr 22 12:12:57 ritsu kernel: 8021q: 802.1Q VLAN Support v1.8 Apr 22 12:12:57 ritsu systemd[1]: Started volumio-remote-updater.service. Apr 22 12:12:57 ritsu systemd[1]: Starting Configure Bluetooth Modems connected by UART... Apr 22 12:12:57 ritsu systemd[1]: Starting Save/Restore Sound Card State... Apr 22 12:12:57 ritsu systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Apr 22 12:12:57 ritsu systemd[1]: Started UPnP Renderer front-end to MPD. Apr 22 12:12:57 ritsu ifup[395]: command failed: No such device (-19) Apr 22 12:12:57 ritsu systemd-logind[460]: New seat seat0. Apr 22 12:12:57 ritsu systemd[1]: Starting triggerhappy global hotkey daemon... Apr 22 12:12:57 ritsu systemd[1]: Started Daily Cleanup of Temporary Directories. Apr 22 12:12:57 ritsu systemd[1]: Started Daily man-db regeneration. Apr 22 12:12:57 ritsu systemd[1]: Reached target Timers. Apr 22 12:12:57 ritsu systemd[1]: Started RPC bind portmap service. Apr 22 12:12:57 ritsu thd[482]: Unable to parse trigger line: Apr 22 12:12:57 ritsu thd[482]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Apr 22 12:12:57 ritsu thd[482]: Unable to parse trigger line: Apr 22 12:12:57 ritsu thd[482]: Found socket passed from systemd Apr 22 12:12:57 ritsu systemd[1]: volumiosplash.service: Main process exited, code=exited, status=203/EXEC Apr 22 12:12:57 ritsu systemd[1]: volumiosplash.service: Failed with result 'exit-code'. Apr 22 12:12:57 ritsu systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Apr 22 12:12:57 ritsu systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Apr 22 12:12:57 ritsu systemd[1]: Failed to start dhcpcd on all interfaces. Apr 22 12:12:57 ritsu systemd[1]: Reached target Remote File Systems (Pre). Apr 22 12:12:57 ritsu systemd[1]: Reached target Remote File Systems. Apr 22 12:12:57 ritsu systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Apr 22 12:12:57 ritsu systemd[1]: Reached target RPC Port Mapper. Apr 22 12:12:57 ritsu systemd[1]: Started triggerhappy global hotkey daemon. Apr 22 12:12:57 ritsu systemd[1]: hciuart.service: Succeeded. Apr 22 12:12:57 ritsu systemd[1]: Started Configure Bluetooth Modems connected by UART. Apr 22 12:12:57 ritsu systemd[1]: Started Save/Restore Sound Card State. Apr 22 12:12:57 ritsu systemd[1]: Reached target Sound Card. Apr 22 12:12:57 ritsu systemd[1]: Starting Raspberry Pi bluetooth helper... Apr 22 12:12:57 ritsu avahi-daemon[476]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Apr 22 12:12:57 ritsu avahi-daemon[476]: Successfully dropped root privileges. Apr 22 12:12:57 ritsu avahi-daemon[476]: avahi-daemon 0.7 starting up. Apr 22 12:12:58 ritsu bthelper[500]: Raspberry Pi BDADDR already set Apr 22 12:12:58 ritsu systemd[1]: Started Raspberry Pi bluetooth helper. Apr 22 12:12:58 ritsu avahi-daemon[476]: Successfully called chroot(). Apr 22 12:12:58 ritsu avahi-daemon[476]: Successfully dropped remaining capabilities. Apr 22 12:12:58 ritsu wpa_supplicant[467]: Successfully initialized wpa_supplicant Apr 22 12:12:58 ritsu avahi-daemon[476]: Loading service file /services/volumio.service. Apr 22 12:12:58 ritsu avahi-daemon[476]: Network interface enumeration completed. Apr 22 12:12:58 ritsu avahi-daemon[476]: Server startup complete. Host name is ritsu.local. Local service cookie is 2211661573. Apr 22 12:12:58 ritsu avahi-daemon[476]: Service "ritsu" (/services/volumio.service) successfully established. Apr 22 12:12:58 ritsu kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Apr 22 12:12:58 ritsu kernel: bcmgenet fd580000.ethernet eth0: Link is Down Apr 22 12:12:58 ritsu sh[394]: eth0: waiting for carrier Apr 22 12:12:58 ritsu dhcpcd[445]: eth0: waiting for carrier Apr 22 12:12:58 ritsu systemd[1]: Started Login Service. Apr 22 12:12:58 ritsu systemd[1]: Started Avahi mDNS/DNS-SD Stack. Apr 22 12:12:58 ritsu systemd[1]: Started WPA supplicant. Apr 22 12:12:58 ritsu systemd[1]: Starting Bluetooth service... Apr 22 12:12:58 ritsu systemd[1]: Started Raise network interfaces. Apr 22 12:12:58 ritsu systemd[1]: Reached target Network. Apr 22 12:12:58 ritsu systemd[1]: Starting Permit User Sessions... Apr 22 12:12:58 ritsu systemd[1]: Starting Network Time Service... Apr 22 12:12:58 ritsu volumio-remote-updater[470]: Error: No active session Apr 22 12:12:58 ritsu volumio-remote-updater[470]: [2025-04-22 12:12:58] [info] asio async_connect error: system:111 (Connection refused) Apr 22 12:12:58 ritsu volumio-remote-updater[470]: [2025-04-22 12:12:58] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 22 12:12:58 ritsu volumio-remote-updater[470]: [2025-04-22 12:12:58] [error] handle_connect error: Underlying Transport Error Apr 22 12:12:58 ritsu systemd[1]: Starting OpenBSD Secure Shell server... Apr 22 12:12:58 ritsu systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Apr 22 12:12:58 ritsu bluetoothd[546]: Bluetooth daemon 5.50 Apr 22 12:12:58 ritsu systemd[1]: Reached target Network is Online. Apr 22 12:12:58 ritsu systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 22 12:12:59 ritsu bluetoothd[546]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Apr 22 12:12:59 ritsu volumio[478]: Could not open config: /tmp/upmpdcli.conf Apr 22 12:12:59 ritsu bluetoothd[546]: Starting SDP server Apr 22 12:12:59 ritsu bluetoothd[546]: Excluding (cli) sap Apr 22 12:12:59 ritsu systemd[1]: Starting Samba NMB Daemon... Apr 22 12:12:59 ritsu systemd[1]: Starting /etc/rc.local Compatibility... Apr 22 12:12:59 ritsu loadcpufreq[488]: Loading cpufreq kernel modules...done (none). Apr 22 12:12:59 ritsu systemd[1]: Starting LSB: Brings up/down network automatically... Apr 22 12:12:59 ritsu kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Apr 22 12:12:59 ritsu kernel: Bluetooth: BNEP filters: protocol multicast Apr 22 12:12:59 ritsu kernel: Bluetooth: BNEP socket layer initialized Apr 22 12:12:59 ritsu systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 22 12:12:59 ritsu systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 22 12:12:59 ritsu bluetoothd[546]: Bluetooth management interface 1.22 initialized Apr 22 12:12:59 ritsu dbus-daemon[450]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 pid=546 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Apr 22 12:12:59 ritsu kernel: Bluetooth: MGMT ver 1.22 Apr 22 12:12:59 ritsu systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Apr 22 12:12:59 ritsu systemd[1]: Started Permit User Sessions. Apr 22 12:12:59 ritsu systemd[1]: Started /etc/rc.local Compatibility. Apr 22 12:12:59 ritsu systemd[1]: iptables.service: Succeeded. Apr 22 12:12:59 ritsu systemd[1]: Started Bluetooth service. Apr 22 12:12:59 ritsu ntpd[574]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 22 12:12:59 ritsu ntpd[574]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Apr 22 12:12:59 ritsu bluetoothd[546]: Failed to set privacy: Rejected (0x0b) Apr 22 12:12:59 ritsu ntpd[609]: proto: precision = 2.148 usec (-19) Apr 22 12:12:59 ritsu ntpd[609]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 22 12:12:59 ritsu ntpd[609]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 22 12:12:59 ritsu ntpd[609]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 116 days ago Apr 22 12:12:59 ritsu ntpd[609]: Listen and drop on 0 v6wildcard [::]:123 Apr 22 12:12:59 ritsu ntpd[609]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 22 12:12:59 ritsu ntpd[609]: Listen normally on 2 lo 127.0.0.1:123 Apr 22 12:12:59 ritsu ntpd[609]: Listening on routing socket on fd #19 for interface updates Apr 22 12:12:59 ritsu ntpd[609]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 22 12:12:59 ritsu ntpd[609]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 22 12:12:59 ritsu systemd[1]: Started Network Time Service. Apr 22 12:12:59 ritsu systemd[1]: Starting Hostname Service... Apr 22 12:12:59 ritsu systemd[1]: Reached target Bluetooth. Apr 22 12:12:59 ritsu systemd[1]: Starting Hold until boot process finishes up... Apr 22 12:12:59 ritsu systemd[1]: Starting Terminate Plymouth Boot Screen... Apr 22 12:12:59 ritsu systemd[1]: Starting LSB: set CPUFreq kernel parameters... Apr 22 12:12:59 ritsu systemd[1]: Received SIGRTMIN+21 from PID 251 (plymouthd). Apr 22 12:12:59 ritsu sshd[618]: Server listening on 0.0.0.0 port 22. Apr 22 12:12:59 ritsu sshd[618]: Server listening on :: port 22. Apr 22 12:12:59 ritsu systemd[1]: Started OpenBSD Secure Shell server. Apr 22 12:12:59 ritsu systemd[1]: plymouth-start.service: Succeeded. Apr 22 12:12:59 ritsu systemd[1]: plymouth-quit-wait.service: Succeeded. Apr 22 12:12:59 ritsu systemd[1]: Started Hold until boot process finishes up. Apr 22 12:12:59 ritsu systemd[1]: plymouth-quit.service: Succeeded. Apr 22 12:12:59 ritsu systemd[1]: Started Terminate Plymouth Boot Screen. Apr 22 12:12:59 ritsu systemd[1]: Received SIGRTMIN+21 from PID 251 (n/a). Apr 22 12:12:59 ritsu ifplugd(eth0)[633]: ifplugd 0.28 initializing. Apr 22 12:12:59 ritsu ifplugd(eth0)[633]: Using interface eth0/E4:5F:01:2F:7D:4D with driver (version: 6.1.69-v7l+) Apr 22 12:12:59 ritsu ifplugd(eth0)[633]: Using detection mode: SIOCETHTOOL Apr 22 12:12:59 ritsu ifplugd(eth0)[633]: Initialization complete, link beat not detected. Apr 22 12:12:59 ritsu ifplugd[602]: Network Interface Plugging Daemon...start eth0...done. Apr 22 12:12:59 ritsu systemd[1]: Started LSB: Brings up/down network automatically. Apr 22 12:13:00 ritsu cpufrequtils[622]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Apr 22 12:13:00 ritsu systemd[1]: Started LSB: set CPUFreq kernel parameters. Apr 22 12:13:00 ritsu dbus-daemon[450]: [system] Successfully activated service 'org.freedesktop.hostname1' Apr 22 12:13:00 ritsu systemd[1]: Started Hostname Service. Apr 22 12:13:00 ritsu nmbd[606]: [2025/04/22 12:13:00.311087, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Apr 22 12:13:00 ritsu nmbd[606]: started asyncdns process 644 Apr 22 12:13:00 ritsu nmbd[606]: [2025/04/22 12:13:00.314081, 0] ../lib/util/become_daemon.c:149(daemon_status) Apr 22 12:13:00 ritsu nmbd[606]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Apr 22 12:13:00 ritsu nmbd[606]: [2025/04/22 12:13:00.315000, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Apr 22 12:13:00 ritsu nmbd[606]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Apr 22 12:13:00 ritsu ntpd[609]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 22 12:13:00 ritsu haveged[419]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Apr 22 12:13:00 ritsu haveged[419]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Apr 22 12:13:00 ritsu haveged[419]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99886 Apr 22 12:13:00 ritsu haveged[419]: haveged: fills: 0, generated: 0 Apr 22 12:13:00 ritsu wireless.js[466]: WIRELESS: No wireless interface, exiting Apr 22 12:13:00 ritsu iw[649]: command failed: No such device (-19) Apr 22 12:13:00 ritsu iwconfig[652]: Error for wireless request "Set Power Management" (8B2C) : Apr 22 12:13:00 ritsu iwconfig[652]: SET failed on device wlan0 ; No such device. Apr 22 12:13:00 ritsu systemd[1]: wireless.service: Succeeded. Apr 22 12:13:00 ritsu systemd[1]: Started Wireless Services. Apr 22 12:13:00 ritsu systemd[1]: Started Volumio Backend Module. Apr 22 12:13:00 ritsu systemd[1]: Started Volumio Cpu Tweaker. Apr 22 12:13:00 ritsu volumio-cpu-tweak[656]: Setting RT Priority for mpd Apr 22 12:13:00 ritsu volumio-cpu-tweak[656]: pid 35's current scheduling policy: SCHED_OTHER Apr 22 12:13:00 ritsu volumio-cpu-tweak[656]: pid 35's current scheduling priority: 0 Apr 22 12:13:00 ritsu volumio-cpu-tweak[656]: Setting MPD Affinity Apr 22 12:13:00 ritsu volumio-cpu-tweak[656]: pid 3's current affinity mask: f Apr 22 12:13:00 ritsu volumio-cpu-tweak[656]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Apr 22 12:13:00 ritsu volumio-cpu-tweak[656]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Apr 22 12:13:00 ritsu systemd[1]: volumio_cpu_tweak.service: Succeeded. Apr 22 12:13:01 ritsu ntpd[609]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 22 12:13:01 ritsu systemd[1]: systemd-rfkill.service: Succeeded. Apr 22 12:13:02 ritsu ntpd[609]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 22 12:13:02 ritsu volumio[655]: info: ------------------------------------------- Apr 22 12:13:02 ritsu volumio[655]: info: ----- Volumio3 ---- Apr 22 12:13:02 ritsu volumio[655]: info: ------------------------------------------- Apr 22 12:13:02 ritsu volumio[655]: info: ----- System startup ---- Apr 22 12:13:02 ritsu volumio[655]: info: ------------------------------------------- Apr 22 12:13:02 ritsu sh[394]: eth0: carrier acquired Apr 22 12:13:02 ritsu dhcpcd[445]: eth0: carrier acquired Apr 22 12:13:02 ritsu sh[394]: DUID 00:01:00:01:2d:bb:b8:f7:e4:5f:01:2f:7d:4d Apr 22 12:13:02 ritsu sh[394]: eth0: IAID 01:2f:7d:4d Apr 22 12:13:02 ritsu dhcpcd[445]: DUID 00:01:00:01:2d:bb:b8:f7:e4:5f:01:2f:7d:4d Apr 22 12:13:02 ritsu dhcpcd[445]: eth0: IAID 01:2f:7d:4d Apr 22 12:13:02 ritsu sh[394]: eth0: adding address fe80::d407:8948:8b97:b02c Apr 22 12:13:02 ritsu sh[394]: ipv6_addaddr1: Permission denied Apr 22 12:13:02 ritsu dhcpcd[445]: eth0: adding address fe80::d407:8948:8b97:b02c Apr 22 12:13:02 ritsu dhcpcd[445]: ipv6_addaddr1: Permission denied Apr 22 12:13:02 ritsu kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Apr 22 12:13:02 ritsu sh[394]: eth0: rebinding lease of 192.168.1.140 Apr 22 12:13:02 ritsu dhcpcd[445]: eth0: rebinding lease of 192.168.1.140 Apr 22 12:13:02 ritsu sh[394]: eth0: probing address 192.168.1.140/24 Apr 22 12:13:02 ritsu dhcpcd[445]: eth0: probing address 192.168.1.140/24 Apr 22 12:13:02 ritsu ifplugd(eth0)[633]: Link beat detected. Apr 22 12:13:03 ritsu ifplugd(eth0)[633]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Apr 22 12:13:03 ritsu ifplugd(eth0)[633]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Apr 22 12:13:03 ritsu volumio[655]: info: MYVOLUMIO Environment detected Apr 22 12:13:03 ritsu bthelper[500]: Changing power off succeeded Apr 22 12:13:03 ritsu volumio[655]: info: Plugin folders cleanup Apr 22 12:13:03 ritsu volumio[655]: info: Scanning into folder /volumio/app/plugins/ Apr 22 12:13:03 ritsu volumio[655]: info: Scanning category audio_interface Apr 22 12:13:03 ritsu volumio[655]: info: Scanning category miscellanea Apr 22 12:13:03 ritsu volumio[655]: info: Scanning category music_service Apr 22 12:13:03 ritsu volumio[655]: info: Scanning category plugins.json Apr 22 12:13:03 ritsu volumio[655]: info: Scanning category system_controller Apr 22 12:13:03 ritsu volumio[655]: info: Scanning category user_interface Apr 22 12:13:03 ritsu volumio[655]: info: Scanning into folder /data/plugins/ Apr 22 12:13:03 ritsu volumio[655]: info: Scanning category music_service Apr 22 12:13:03 ritsu volumio[655]: info: Scanning category user_interface Apr 22 12:13:03 ritsu volumio[655]: info: Plugin folders cleanup completed Apr 22 12:13:03 ritsu volumio[655]: info: ------------------------------------------- Apr 22 12:13:03 ritsu volumio[655]: info: ----- Core plugins startup ---- Apr 22 12:13:03 ritsu volumio[655]: info: ------------------------------------------- Apr 22 12:13:03 ritsu volumio[655]: info: Loading plugins from folder /volumio/app/plugins/ Apr 22 12:13:03 ritsu volumio[655]: info: Adding plugin upnp to MyMusic Plugins Apr 22 12:13:03 ritsu volumio[655]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 22 12:13:03 ritsu volumio[655]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 22 12:13:03 ritsu volumio[655]: info: Loading plugins from folder /data/plugins/ Apr 22 12:13:03 ritsu volumio[655]: info: Loading plugin "system"... Apr 22 12:13:03 ritsu bthelper[500]: [CHG] Controller E4:5F:01:2F:7D:4F Class: 0x0000041c Apr 22 12:13:03 ritsu bthelper[500]: Changing power on succeeded Apr 22 12:13:03 ritsu bthelper[500]: [CHG] Controller E4:5F:01:2F:7D:4F Powered: yes Apr 22 12:13:03 ritsu volumio[655]: info: Loading plugin "appearance"... Apr 22 12:13:03 ritsu ntpd[609]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 22 12:13:03 ritsu sh[394]: eth0: soliciting an IPv6 router Apr 22 12:13:03 ritsu dhcpcd[445]: eth0: soliciting an IPv6 router Apr 22 12:13:03 ritsu volumio-remote-updater[470]: [2025-04-22 12:13:03] [connect] Successful connection Apr 22 12:13:04 ritsu volumio[655]: info: Loading plugin "network"... Apr 22 12:13:04 ritsu volumio[655]: info: Refreshing Cached IP Addresses Apr 22 12:13:04 ritsu volumio[655]: info: Loading plugin "services"... Apr 22 12:13:04 ritsu volumio[655]: info: Loading plugin "alsa_controller"... Apr 22 12:13:04 ritsu sudo[699]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 22 12:13:04 ritsu sudo[703]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 22 12:13:04 ritsu sudo[703]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:04 ritsu sudo[701]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 22 12:13:04 ritsu sudo[701]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:04 ritsu sudo[699]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:04 ritsu sudo[699]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:04 ritsu sudo[703]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:04 ritsu sudo[701]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:04 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 22 12:13:04 ritsu volumio[655]: info: Loading plugin "wizard"... Apr 22 12:13:04 ritsu volumio[655]: info: Loading plugin "networkfs"... Apr 22 12:13:04 ritsu volumio[655]: info: Starting Udev Watcher for removable devices Apr 22 12:13:04 ritsu sudo[714]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=nazuna,password=xvH^V!4D3UNrqdQP!WG3p6hsfbW@&KPxJU8K2SW9,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.136/ongaku /mnt/NAS/nazuna Apr 22 12:13:04 ritsu sudo[714]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:04 ritsu volumio[655]: info: Ignoring mount for partition: boot Apr 22 12:13:04 ritsu volumio[655]: info: Ignoring mount for partition: volumio Apr 22 12:13:04 ritsu volumio[655]: info: Ignoring mount for partition: volumio_data Apr 22 12:13:04 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 22 12:13:04 ritsu volumio[655]: info: Loading plugin "volumio_command_line_client"... Apr 22 12:13:04 ritsu volumio[655]: info: Loading plugin "upnp"... Apr 22 12:13:04 ritsu volumio[655]: info: [1745341984494] Starting Upmpd Daemon Apr 22 12:13:04 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 22 12:13:04 ritsu volumio[655]: info: Loading plugin "my_music"... Apr 22 12:13:04 ritsu volumio[655]: info: Loading plugin "mpd"... Apr 22 12:13:04 ritsu sudo[714]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:04 ritsu kernel: Key type cifs.spnego registered Apr 22 12:13:04 ritsu kernel: Key type cifs.idmap registered Apr 22 12:13:04 ritsu 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. Apr 22 12:13:04 ritsu kernel: CIFS: Attempting to mount \\192.168.1.136\ongaku Apr 22 12:13:04 ritsu kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 22 12:13:04 ritsu kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Apr 22 12:13:04 ritsu volumio[655]: info: Loading plugin "upnp_browser"... Apr 22 12:13:05 ritsu volumio[655]: info: Loading plugin "alarm-clock"... Apr 22 12:13:05 ritsu volumio[655]: info: Loading plugin "airplay_emulation"... Apr 22 12:13:05 ritsu volumio[655]: info: Starting Shairport Sync Apr 22 12:13:05 ritsu volumio[655]: info: Loading plugin "last_100"... Apr 22 12:13:05 ritsu volumio[655]: info: Loading plugin "webradio"... Apr 22 12:13:05 ritsu volumio[655]: info: Loading plugin "i2s_dacs"... Apr 22 12:13:05 ritsu volumio[655]: info: Loading plugin "volumiodiscovery"... Apr 22 12:13:05 ritsu volumio[655]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 22 12:13:05 ritsu node[655]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 22 12:13:05 ritsu volumio[655]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 22 12:13:05 ritsu node[655]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 22 12:13:05 ritsu volumio[655]: *** WARNING *** For more information see Apr 22 12:13:05 ritsu node[655]: *** WARNING *** For more information see Apr 22 12:13:05 ritsu volumio[655]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 22 12:13:05 ritsu node[655]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 22 12:13:05 ritsu volumio[655]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 22 12:13:05 ritsu node[655]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 22 12:13:05 ritsu volumio[655]: *** WARNING *** For more information see Apr 22 12:13:05 ritsu node[655]: *** WARNING *** For more information see Apr 22 12:13:05 ritsu volumio[655]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 22 12:13:05 ritsu volumio[655]: info: Discovery: Started advertising with name: ritsu Apr 22 12:13:05 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 22 12:13:05 ritsu volumio[655]: info: Loading plugin "bandcamp"... Apr 22 12:13:06 ritsu volumio[655]: info: Loading plugin "soundcloud"... Apr 22 12:13:06 ritsu volumio[655]: info: Loading plugin "spop"... Apr 22 12:13:07 ritsu volumio[655]: info: Loading plugin "squeezelite_mc"... Apr 22 12:13:08 ritsu volumio[655]: info: Loading plugin "ytcr"... Apr 22 12:13:08 ritsu sh[394]: eth0: leased 192.168.1.140 for infinity Apr 22 12:13:08 ritsu dhcpcd[445]: eth0: leased 192.168.1.140 for infinity Apr 22 12:13:08 ritsu sh[394]: eth0: adding route to 192.168.1.0/24 Apr 22 12:13:08 ritsu sh[394]: eth0: adding default route via 192.168.1.1 Apr 22 12:13:08 ritsu avahi-daemon[476]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.140. Apr 22 12:13:08 ritsu avahi-daemon[476]: New relevant interface eth0.IPv4 for mDNS. Apr 22 12:13:08 ritsu dhcpcd[445]: eth0: adding route to 192.168.1.0/24 Apr 22 12:13:08 ritsu dhcpcd[445]: eth0: adding default route via 192.168.1.1 Apr 22 12:13:08 ritsu avahi-daemon[476]: Registering new address record for 192.168.1.140 on eth0.IPv4. Apr 22 12:13:08 ritsu sh[394]: forked to background, child pid 747 Apr 22 12:13:08 ritsu dhcpcd[445]: forked to background, child pid 747 Apr 22 12:13:08 ritsu ifplugd(eth0)[633]: client: ifup: interface eth0 already configured Apr 22 12:13:08 ritsu sh[394]: eth0=eth0 Apr 22 12:13:08 ritsu ifplugd(eth0)[633]: Program executed successfully. Apr 22 12:13:09 ritsu volumio[655]: info: Loading plugin "ytmusic"... Apr 22 12:13:10 ritsu ntpd[609]: Listen normally on 3 eth0 192.168.1.140:123 Apr 22 12:13:10 ritsu ntpd[609]: new interface(s) found: waking up resolver Apr 22 12:13:10 ritsu nmbd[606]: [2025/04/22 12:13:10.318804, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 22 12:13:10 ritsu nmbd[606]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Apr 22 12:13:10 ritsu systemd[1]: Started Samba NMB Daemon. Apr 22 12:13:10 ritsu nmbd[606]: [2025/04/22 12:13:10.333125, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Apr 22 12:13:10 ritsu nmbd[606]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.140 for name WORKGROUP<1d>. Apr 22 12:13:10 ritsu nmbd[606]: This response was from IP 192.168.1.100, reporting an IP address of 192.168.1.100. Apr 22 12:13:10 ritsu systemd[1]: Starting Samba Winbind Daemon... Apr 22 12:13:10 ritsu volumio[655]: info: Loading plugin "now_playing"... Apr 22 12:13:10 ritsu winbindd[773]: [2025/04/22 12:13:10.594480, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 22 12:13:10 ritsu winbindd[773]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 22 12:13:10 ritsu winbindd[773]: [2025/04/22 12:13:10.607736, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 22 12:13:10 ritsu winbindd[773]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 22 12:13:10 ritsu systemd[1]: Started Samba Winbind Daemon. Apr 22 12:13:10 ritsu systemd[1]: Starting Samba SMB Daemon... Apr 22 12:13:11 ritsu smbd[778]: [2025/04/22 12:13:11.005295, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 22 12:13:11 ritsu smbd[778]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 22 12:13:11 ritsu systemd[1]: Started Samba SMB Daemon. Apr 22 12:13:11 ritsu systemd[1]: Reached target Multi-User System. Apr 22 12:13:11 ritsu systemd[1]: Reached target Graphical Interface. Apr 22 12:13:11 ritsu systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 22 12:13:11 ritsu systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 22 12:13:11 ritsu systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 22 12:13:11 ritsu systemd[1]: Startup finished in 9.428s (kernel) + 19.712s (userspace) = 29.140s. Apr 22 12:13:11 ritsu volumio[655]: info: Loading plugin "outputs"... Apr 22 12:13:11 ritsu volumio[655]: info: Loading plugin "albumart"... Apr 22 12:13:11 ritsu volumio[655]: info: Plugin example_plugin is not enabled Apr 22 12:13:11 ritsu volumio[655]: info: Loading plugin "inputs"... Apr 22 12:13:11 ritsu volumio[655]: info: Loading plugin "updater_comm"... Apr 22 12:13:11 ritsu volumio[655]: info: Plugin mpdemulation is not enabled Apr 22 12:13:11 ritsu volumio[655]: info: Loading plugin "rest_api"... Apr 22 12:13:11 ritsu volumio[655]: info: Loading plugin "websocket"... Apr 22 12:13:11 ritsu volumio[655]: info: Plugin volroon is not enabled Apr 22 12:13:11 ritsu volumio[655]: info: Loading plugin "touch_display"... Apr 22 12:13:11 ritsu volumio[655]: Forking 3 albumart workers Apr 22 12:13:12 ritsu volumio[655]: info: Applying required configuration parameters for plugin touch_display Apr 22 12:13:12 ritsu volumio[655]: info: Loading i18n strings for locale en Apr 22 12:13:12 ritsu volumio[655]: Updating browse sources language Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::initPlayerControls Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:12 ritsu volumio[655]: Starting albumart workers Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 22 12:13:12 ritsu volumio[655]: Express server listening on port 3000 Apr 22 12:13:12 ritsu volumio[655]: [Metrics] WebUI: 10s 842.53ms Apr 22 12:13:12 ritsu volumio[655]: info: CoreStateMachine::resetVolumioState Apr 22 12:13:12 ritsu volumio[655]: info: CoreStateMachine::getcurrentVolume Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::volumioRetrievevolume Apr 22 12:13:12 ritsu volumio[655]: info: CoreStateMachine::pushState Apr 22 12:13:12 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:12 ritsu volumio[655]: Starting albumart workers Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 22 12:13:12 ritsu volumio[655]: info: CoreCommandRouter::volumioPushState Apr 22 12:13:12 ritsu volumio[655]: Starting albumart workers Apr 22 12:13:12 ritsu volumio[655]: info: Cannot mount NAS nazuna at system boot, trial number 1 ,retrying in 5 seconds Apr 22 12:13:12 ritsu volumio[655]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Apr 22 12:13:12 ritsu volumio[655]: wlan0 Interface doesn't support scanning. Apr 22 12:13:12 ritsu volumio[655]: info: Cannot use regular scanning, forcing with ap-force Apr 22 12:13:12 ritsu sudo[819]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Apr 22 12:13:12 ritsu sudo[819]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:12 ritsu sudo[819]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:12 ritsu volumio[655]: command failed: No such device (-19) Apr 22 12:13:12 ritsu volumio[655]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Apr 22 12:13:12 ritsu volumio[655]: command failed: No such device (-19) Apr 22 12:13:12 ritsu volumio[655]: verbose: New Socket.io Connection to 192.168.1.140 from 192.168.1.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Mobile Safari/537.36 Total Clients: 1 Apr 22 12:13:12 ritsu volumio[655]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 22 12:13:13 ritsu volumio[655]: info: Reloading queue from file Apr 22 12:13:13 ritsu volumio[655]: info: CoreStateMachine::setRepeat true single undefined Apr 22 12:13:13 ritsu volumio[655]: info: CoreStateMachine::pushState Apr 22 12:13:13 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioPushState Apr 22 12:13:13 ritsu volumio[655]: info: CoreStateMachine::setRandom true Apr 22 12:13:13 ritsu volumio[655]: info: CoreStateMachine::pushState Apr 22 12:13:13 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioPushState Apr 22 12:13:13 ritsu volumio[655]: info: Setting Device type: Raspberry PI Apr 22 12:13:13 ritsu volumio[655]: info: Completed loading Core Plugins Apr 22 12:13:13 ritsu volumio[655]: info: Preparing to generate the ALSA configuration file Apr 22 12:13:13 ritsu volumio[655]: info: Discovery: adding d7c3008b-4123-4645-bb83-09db5398bd46 Apr 22 12:13:13 ritsu volumio[655]: info: Discovery: Found device ritsu Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioGetState Apr 22 12:13:13 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:13 ritsu volumio[655]: info: Asound.conf file unchanged, so no further update is needed Apr 22 12:13:13 ritsu volumio[655]: info: Output device has changed, restarting MPD Apr 22 12:13:13 ritsu sudo[845]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 22 12:13:13 ritsu sudo[845]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:13 ritsu volumio[655]: info: Output device has changed, restarting Shairport Sync Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 22 12:13:13 ritsu sudo[845]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:13 ritsu sudo[856]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 22 12:13:13 ritsu sudo[856]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:13 ritsu volumio[655]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 22 12:13:13 ritsu volumio[655]: info: ___________ START PLUGINS ___________ Apr 22 12:13:13 ritsu volumio[655]: info: ControllerMpd::onStart: Initializing MPD Apr 22 12:13:13 ritsu volumio[655]: info: Creating MPD Configuration file Apr 22 12:13:13 ritsu systemd[1]: Listening on mpd.socket. Apr 22 12:13:13 ritsu sudo[863]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 22 12:13:13 ritsu sudo[863]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:13 ritsu systemd[1]: Starting Music Player Daemon... Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 22 12:13:13 ritsu volumio[655]: info: [1745341993310] CoreMusicLibrary::Adding element Media Servers Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 22 12:13:13 ritsu sudo[867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 22 12:13:13 ritsu sudo[867]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:13 ritsu sudo[863]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 22 12:13:13 ritsu systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 22 12:13:13 ritsu systemd[1]: mpd.service: Succeeded. Apr 22 12:13:13 ritsu systemd[1]: Stopped Music Player Daemon. Apr 22 12:13:13 ritsu systemd[1]: Starting Music Player Daemon... Apr 22 12:13:13 ritsu volumio[655]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 22 12:13:13 ritsu volumio[655]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 22 12:13:13 ritsu volumio[655]: info: [1745341993425] CoreMusicLibrary::Adding element Last_100 Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 22 12:13:13 ritsu volumio[655]: info: [1745341993428] CoreMusicLibrary::Adding element Webradio Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 22 12:13:13 ritsu volumio[655]: info: [1745341993444] CoreMusicLibrary::Adding element Bandcamp Discover Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 22 12:13:13 ritsu volumio[655]: Cannot find translation for source Bandcamp Discover Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 22 12:13:13 ritsu volumio[655]: info: [1745341993455] CoreMusicLibrary::Adding element SoundCloud Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 22 12:13:13 ritsu volumio[655]: Cannot find translation for source Bandcamp Discover Apr 22 12:13:13 ritsu volumio[655]: Cannot find translation for source SoundCloud Apr 22 12:13:13 ritsu volumio[655]: info: Creating Spotify config file Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:13 ritsu volumio[655]: info: [squeezelite_mc] Starting proxy server... Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 22 12:13:13 ritsu volumio[655]: info: [1745341993570] CoreMusicLibrary::Adding element YouTube Music Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 22 12:13:13 ritsu volumio[655]: Cannot find translation for source Bandcamp Discover Apr 22 12:13:13 ritsu volumio[655]: Cannot find translation for source SoundCloud Apr 22 12:13:13 ritsu volumio[655]: Cannot find translation for source YouTube Music Apr 22 12:13:13 ritsu volumio[655]: info: [now-playing] ConfigUpdater: config is up to date. Apr 22 12:13:13 ritsu volumio[655]: info: Loading i18n strings for locale en Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 22 12:13:13 ritsu volumio[655]: info: Volumio Calling Home Apr 22 12:13:13 ritsu volumio[655]: info: [squeezelite_mc] Proxy server started on port 45571 Apr 22 12:13:13 ritsu sudo[880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Apr 22 12:13:13 ritsu sudo[880]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:13 ritsu sudo[883]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Apr 22 12:13:13 ritsu sudo[883]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:13 ritsu sudo[886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Apr 22 12:13:13 ritsu sudo[886]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioRetrievevolume Apr 22 12:13:13 ritsu volumio[655]: info: [now-playing] App is listening on port 4004. Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioGetState Apr 22 12:13:13 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:13 ritsu volumio[655]: info: CoreStateMachine::pushState Apr 22 12:13:13 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::volumioPushState Apr 22 12:13:13 ritsu volumio[655]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Apr 22 12:13:13 ritsu volumio[655]: info: [squeezelite_mc] Server discovery started Apr 22 12:13:13 ritsu volumio[655]: info: [squeezelite_mc] Player finder started Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:13 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 22 12:13:13 ritsu volumio[655]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true Apr 22 12:13:13 ritsu systemd[1]: Reloading. Apr 22 12:13:13 ritsu volumio[655]: error: touch_display: Error detecting backlight interface: Error: ENOENT: no such file or directory, scandir '/sys/class/backlight/' Apr 22 12:13:13 ritsu volumio[655]: info: MPD Permissions set Apr 22 12:13:13 ritsu volumio[655]: info: MPD Permissions set Apr 22 12:13:13 ritsu volumio[655]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.1.100","name":"nori","ver":"8.5.2","uuid":"23e9593a-fbe7-4e14-9826-d8f1fe2bc3d7","jsonPort":"9000","cliPort":"9090"} Apr 22 12:13:13 ritsu volumio[655]: info: [squeezelite_mc] Card 2 supports the following ALSA formats: ["S16_LE","S24_LE"] Apr 22 12:13:13 ritsu volumio[655]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"ritsu","dsdFormat":null,"card":"2","mixerType":"None","mixer":null} Apr 22 12:13:14 ritsu volumio[655]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Apr 22 12:13:14 ritsu volumio[655]: info: Spotify config file written Apr 22 12:13:14 ritsu sudo[907]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 22 12:13:14 ritsu sudo[907]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu sudo[905]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Apr 22 12:13:14 ritsu sudo[905]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu sudo[905]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:14 ritsu 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. Apr 22 12:13:14 ritsu volumio[655]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 22 12:13:14 ritsu volumio[655]: info: No need to fix Spotify hosts Apr 22 12:13:14 ritsu volumio[655]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Apr 22 12:13:14 ritsu volumio[655]: info: Volumio called home Apr 22 12:13:14 ritsu sudo[920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Apr 22 12:13:14 ritsu sudo[920]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu volumio[655]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Apr 22 12:13:14 ritsu sudo[920]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:14 ritsu sudo[923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Apr 22 12:13:14 ritsu sudo[923]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu sudo[923]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:14 ritsu volumio[655]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Apr 22 12:13:14 ritsu volumio[655]: info: Starting Shairport Sync Apr 22 12:13:14 ritsu volumio[655]: info: Starting Shairport Sync Apr 22 12:13:14 ritsu sudo[930]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 22 12:13:14 ritsu sudo[930]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu volumio[655]: info: Starting Shairport Sync Apr 22 12:13:14 ritsu systemd[1]: Reloading. Apr 22 12:13:14 ritsu sudo[927]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Apr 22 12:13:14 ritsu sudo[927]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu sudo[927]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:14 ritsu sudo[886]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:14 ritsu sudo[932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 22 12:13:14 ritsu sudo[932]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu volumio[655]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 22 12:13:14 ritsu volumio[655]: SPOTIFY: BQB4SWdYCU8Rg4zbzQayPztkLkogJDsO2w4uczLw7juACKr2YacFNMOCKfREhrrE539fD80QHK_gxxpNdjsy7CV9gyMQWhiEb04BG2IxVstSQNTBZiivfojwcwGhKBaVQy85QeHlHqqrVu7qFt5wIwrb1EunUkqTKoyIWbZZG5Zw0khVBlyMqdeFVmU2MagQH9HRjWkVP_D2-T9MNN3S2o2E9KpQ7f0cdwrxK4pjUebe6xNV8Aj1CFaOMnv0VCRPfjU4ZEpC3vGwPcwRUq1t87tH Apr 22 12:13:14 ritsu volumio[655]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 22 12:13:14 ritsu volumio[655]: info: New Spotify access token = BQB4SWdYCU8Rg4zbzQayPztkLkogJDsO2w4uczLw7juACKr2YacFNMOCKfREhrrE539fD80QHK_gxxpNdjsy7CV9gyMQWhiEb04BG2IxVstSQNTBZiivfojwcwGhKBaVQy85QeHlHqqrVu7qFt5wIwrb1EunUkqTKoyIWbZZG5Zw0khVBlyMqdeFVmU2MagQH9HRjWkVP_D2-T9MNN3S2o2E9KpQ7f0cdwrxK4pjUebe6xNV8Aj1CFaOMnv0VCRPfjU4ZEpC3vGwPcwRUq1t87tH Apr 22 12:13:14 ritsu volumio[655]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 22 12:13:14 ritsu sudo[936]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 22 12:13:14 ritsu sudo[936]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu volumio[655]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Apr 22 12:13:14 ritsu sudo[947]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 22 12:13:14 ritsu sudo[947]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu sudo[947]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:14 ritsu sudo[953]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 22 12:13:14 ritsu sudo[953]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu volumio[655]: verbose: New Socket.io Connection to 192.168.1.140 from 192.168.1.148 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Mobile Safari/537.36 Total Clients: 4 Apr 22 12:13:14 ritsu volumio[655]: info: touch_display: systemctl daemon-reload succeeded. Apr 22 12:13:14 ritsu sudo[953]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:14 ritsu volumio[655]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Apr 22 12:13:14 ritsu sudo[960]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Apr 22 12:13:14 ritsu sudo[960]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu sudo[963]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Apr 22 12:13:14 ritsu sudo[963]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu 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. Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::volumioGetState Apr 22 12:13:14 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:14 ritsu sudo[966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 22 12:13:14 ritsu sudo[966]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:14 ritsu volumio[655]: SPOTIFY: User informations: {"country":"US","display_name":"dd","email":"heavy.home2486@fastmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/ipickering2"},"followers":{"href":null,"total":8},"href":"https://api.spotify.com/v1/users/ipickering2","id":"ipickering2","images":[],"product":"premium","type":"user","uri":"spotify:user:ipickering2"} Apr 22 12:13:14 ritsu volumio[655]: info: Spotify Successfully logged in Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 22 12:13:14 ritsu volumio[655]: info: [1745341994941] CoreMusicLibrary::Adding element Spotify Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 22 12:13:14 ritsu volumio[655]: Cannot find translation for source Bandcamp Discover Apr 22 12:13:14 ritsu volumio[655]: Cannot find translation for source SoundCloud Apr 22 12:13:14 ritsu volumio[655]: Cannot find translation for source YouTube Music Apr 22 12:13:14 ritsu volumio[655]: Cannot find translation for source Spotify Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 22 12:13:14 ritsu volumio[655]: info: CoreCommandRouter::volumioGetState Apr 22 12:13:14 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:15 ritsu volumio[655]: info: CoreCommandRouter::volumioGetVisibleSources Apr 22 12:13:15 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 22 12:13:15 ritsu volumio[655]: info: CoreCommandRouter::volumioGetQueue Apr 22 12:13:15 ritsu volumio[655]: info: CoreStateMachine::getQueue Apr 22 12:13:15 ritsu volumio[655]: info: CorePlayQueue::getQueue Apr 22 12:13:15 ritsu volumio[655]: info: Listing playlists Apr 22 12:13:15 ritsu sudo[883]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:15 ritsu sudo[880]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:15 ritsu volumio[655]: info: touch_display: systemctl disable getty@tty1.service succeeded. Apr 22 12:13:15 ritsu volumio[655]: info: touch_display: systemctl stop getty@tty1.service succeeded. Apr 22 12:13:15 ritsu systemd[1]: Reloading. Apr 22 12:13:15 ritsu mpd[870]: Apr 22 12:13 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 22 12:13:15 ritsu volumio[655]: info: [yt-cast-receiver] DIAL server listening on port 8098 Apr 22 12:13:15 ritsu 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. Apr 22 12:13:15 ritsu sudo[963]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:15 ritsu volumio[655]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Apr 22 12:13:15 ritsu systemd[1]: Started UPnP Renderer front-end to MPD. Apr 22 12:13:15 ritsu systemd[1]: Started go-librespot Daemon. Apr 22 12:13:15 ritsu sudo[966]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:15 ritsu sudo[907]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:15 ritsu systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 22 12:13:15 ritsu systemd[1]: Started Volumio Kiosk. Apr 22 12:13:15 ritsu go-librespot[983]: Librespot-go daemon starting... Apr 22 12:13:15 ritsu sudo[960]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:15 ritsu systemd[1]: shairport-sync.service: Succeeded. Apr 22 12:13:15 ritsu systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 22 12:13:15 ritsu volumio[655]: info: Upmpdcli Daemon Started Apr 22 12:13:15 ritsu sudo[985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Apr 22 12:13:15 ritsu sudo[985]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:15 ritsu volumio[655]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Apr 22 12:13:15 ritsu volumio[655]: info: touch_display: Volumio Kiosk started. Apr 22 12:13:15 ritsu systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 22 12:13:15 ritsu sudo[932]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:15 ritsu sudo[936]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:15 ritsu sudo[930]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:16 ritsu volumio[655]: info: CoreCommandRouter::volumioGetState Apr 22 12:13:16 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:16 ritsu volumio[655]: info: CoreCommandRouter::volumioGetState Apr 22 12:13:16 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:16 ritsu volumio[655]: info: Shairport-Sync Started Apr 22 12:13:16 ritsu volumio[655]: Error adding Membership: Error: addMembership EINVAL Apr 22 12:13:16 ritsu volumio[655]: info: Shairport-Sync Started Apr 22 12:13:16 ritsu volumio[655]: info: Shairport-Sync Started Apr 22 12:13:16 ritsu sudo[985]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:16 ritsu volumio[655]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Apr 22 12:13:16 ritsu volumio[655]: info: touch_display: X display number found: Apr 22 12:13:16 ritsu sudo[1015]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Apr 22 12:13:16 ritsu sudo[1015]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:16 ritsu systemd[1]: Starting Squeezelite lightweight headless Squeezebox emulator... Apr 22 12:13:16 ritsu volumio[655]: info: touch_display: X display number found: 0 Apr 22 12:13:16 ritsu systemd[1]: Started Squeezelite lightweight headless Squeezebox emulator. Apr 22 12:13:16 ritsu kernel: process '/opt/squeezelite/squeezelite' started with executable stack Apr 22 12:13:16 ritsu sudo[1015]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:16 ritsu startx[984]: X.Org X Server 1.20.4 Apr 22 12:13:16 ritsu startx[984]: X Protocol Version 11, Revision 0 Apr 22 12:13:16 ritsu startx[984]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Apr 22 12:13:16 ritsu startx[984]: Current Operating System: Linux ritsu 6.1.69-v7l+ #1710 SMP Thu Dec 21 13:17:38 GMT 2023 armv7l Apr 22 12:13:16 ritsu startx[984]: 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=1024 bcm2708_fb.fbheight=600 bcm2708_fb.fbswap=1 smsc95xx.macaddr=E4:5F:01:2F:7D:4D 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=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh rootwait bootdelay=5 elevator=noop 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 Apr 22 12:13:16 ritsu startx[984]: Build Date: 04 April 2023 07:50:56AM Apr 22 12:13:16 ritsu startx[984]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Apr 22 12:13:16 ritsu startx[984]: Current version of pixman: 0.36.0 Apr 22 12:13:16 ritsu startx[984]: Before reporting problems, check http://wiki.x.org Apr 22 12:13:16 ritsu startx[984]: to make sure that you have the latest version. Apr 22 12:13:16 ritsu startx[984]: Markers: (--) probed, (**) from config file, (==) default setting, Apr 22 12:13:16 ritsu startx[984]: (++) from command line, (!!) notice, (II) informational, Apr 22 12:13:16 ritsu startx[984]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Apr 22 12:13:16 ritsu startx[984]: (==) Log file: "/var/log/Xorg.0.log", Time: Tue Apr 22 12:13:16 2025 Apr 22 12:13:16 ritsu volumio[655]: info: touch_display: X display number found: 0 Apr 22 12:13:16 ritsu startx[984]: (==) Using config directory: "/etc/X11/xorg.conf.d" Apr 22 12:13:16 ritsu startx[984]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Apr 22 12:13:16 ritsu go-librespot[983]: time="2025-04-22T12:13:16-05:00" level=info msg="generated new device id: fae6a6d0c5de00d354344054dfcea9be945c49a5" Apr 22 12:13:16 ritsu go-librespot[983]: time="2025-04-22T12:13:16-05:00" level=debug msg="stored credentials found for ipickering2" Apr 22 12:13:16 ritsu volumio-remote-updater[470]: [2025-04-22 12:13:16] [connect] Successful connection Apr 22 12:13:16 ritsu volumio[655]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Apr 22 12:13:16 ritsu volumio-remote-updater[470]: [2025-04-22 12:13:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1745341996 101 Apr 22 12:13:16 ritsu volumio[655]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 5 Apr 22 12:13:16 ritsu volumio[655]: info: touch_display: X display number found: 0 Apr 22 12:13:16 ritsu volumio[655]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Apr 22 12:13:16 ritsu sudo[1037]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Apr 22 12:13:16 ritsu sudo[1037]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:16 ritsu sudo[1037]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:16 ritsu go-librespot[983]: time="2025-04-22T12:13:16-05: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]" Apr 22 12:13:16 ritsu go-librespot[983]: time="2025-04-22T12:13:16-05: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]" Apr 22 12:13:16 ritsu go-librespot[983]: time="2025-04-22T12:13:16-05: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]" Apr 22 12:13:16 ritsu go-librespot[983]: time="2025-04-22T12:13:16-05:00" level=debug msg="zeroconf server listening on port 43767" Apr 22 12:13:16 ritsu go-librespot[983]: time="2025-04-22T12:13:16-05:00" level=debug msg="obtained new client token: AADZkEzeaX+sXZ+KbGCuPEE/eUfptSKP04j1HBv9iIEiAO1DWEfOfIDW3krThKTx2+lEXzLndhKFkKkjmhTQZyYFUuJDftjovc2cqCdkiheeL/OtHXDfi7uKJcjfv8lQbOzwjyUDXPAeC09wBvTgIAMyLaT81PYDhLHtx6TuabMH54u9VeS/WWVPYjYUSWGwZVZ8ZJbFRAmReJe5n9ZpCzkXNOFaQmxWve12Quo8TEF+/DIMx9z1kVA1uOA=" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=info msg="connected to ap-guc3.spotify.com:4070" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="completed keyexchange" Apr 22 12:13:17 ritsu volumio[655]: info: [squeezelite_mc] Notification listener started Apr 22 12:13:17 ritsu volumio[655]: info: [squeezelite_mc] Getting players connected to nori (192.168.1.100) Apr 22 12:13:17 ritsu volumio[655]: info: [squeezelite_mc] Players connected to nori (192.168.1.100): [{"id":"e4:5f:01:2f:7d:4d","uuid":null,"ip":"192.168.1.140","name":"ritsu","server":{"ip":"192.168.1.100","name":"nori","ver":"8.5.2","uuid":"23e9593a-fbe7-4e14-9826-d8f1fe2bc3d7","jsonPort":"9000","cliPort":"9090"}}] Apr 22 12:13:17 ritsu volumio[655]: info: [squeezelite_mc] Player found: {"id":"e4:5f:01:2f:7d:4d","uuid":null,"ip":"192.168.1.140","name":"ritsu","server":{"ip":"192.168.1.100","name":"nori","ver":"8.5.2","uuid":"23e9593a-fbe7-4e14-9826-d8f1fe2bc3d7","jsonPort":"9000","cliPort":"9090"}} Apr 22 12:13:17 ritsu systemd[1]: Started Music Player Daemon. Apr 22 12:13:17 ritsu sudo[867]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:17 ritsu sudo[856]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:17 ritsu volumio[655]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Apr 22 12:13:17 ritsu volumio[655]: info: MPD running with PID870 Apr 22 12:13:17 ritsu volumio[655]: ,establishing connection Apr 22 12:13:17 ritsu sudo[1044]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Apr 22 12:13:17 ritsu sudo[1044]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:17 ritsu sudo[1044]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:17 ritsu volumio[655]: error: MPD error: The expression evaluated to a falsy value: Apr 22 12:13:17 ritsu volumio[655]: assert.ok(self.idling) Apr 22 12:13:17 ritsu volumio[655]: error: The expression evaluated to a falsy value: Apr 22 12:13:17 ritsu volumio[655]: assert.ok(self.idling) Apr 22 12:13:17 ritsu volumio[655]: error: MPD error: The expression evaluated to a falsy value: Apr 22 12:13:17 ritsu volumio[655]: assert.ok(self.idling) Apr 22 12:13:17 ritsu volumio[655]: error: The expression evaluated to a falsy value: Apr 22 12:13:17 ritsu volumio[655]: assert.ok(self.idling) Apr 22 12:13:17 ritsu volumio[655]: error: updateQueue error: null Apr 22 12:13:17 ritsu volumio[981]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="completed challenge" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="authenticated as ipickering2" Apr 22 12:13:17 ritsu volumio[655]: info: CoreCommandRouter::volumioGetState Apr 22 12:13:17 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:17 ritsu volumio[655]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 22 12:13:17 ritsu sudo[1092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=nazuna,password=xvH^V!4D3UNrqdQP!WG3p6hsfbW@&KPxJU8K2SW9,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.136/ongaku /mnt/NAS/nazuna Apr 22 12:13:17 ritsu sudo[1092]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:17 ritsu kernel: CIFS: Attempting to mount \\192.168.1.136\ongaku Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="authenticated as ipickering2" Apr 22 12:13:17 ritsu sudo[1092]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:17 ritsu volumio[655]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Apr 22 12:13:17 ritsu sudo[1110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Apr 22 12:13:17 ritsu sudo[1110]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:17 ritsu sudo[1110]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="dealer connection opened" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="initializing zeroconf session, username: ipickering2" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="autoplay enabled: false" Apr 22 12:13:17 ritsu go-librespot[983]: time="2025-04-22T12:13:17-05:00" level=debug msg="received connection id: NDRiMmM5NmItMzgzOC00NzMyLTliZWItZGY5NzJiYWJiNGVkK2RlYWxlcit0Y3A6Ly8wYWNiZDlmOS5pcC5ndWMzLnNwb3RpZnkubmV0OjU3MDArRkY3NTkzQjVBRTM5MkRBQkIzOEE4RDdFNjM0QjkzRTNGQ0NFNDM5Mjc5REFBMTYzMjM0RDBGNTE0QUMwNDI0NA==" Apr 22 12:13:18 ritsu go-librespot[983]: time="2025-04-22T12:13:18-05:00" level=debug msg="put connect state because NEW_DEVICE" Apr 22 12:13:18 ritsu volumio[655]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Apr 22 12:13:18 ritsu sudo[1141]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Apr 22 12:13:18 ritsu sudo[1141]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:18 ritsu sudo[1141]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:18 ritsu volumio[655]: info: go-librespot daemon successfully initialized Apr 22 12:13:19 ritsu volumio[655]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Apr 22 12:13:19 ritsu sudo[1165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Apr 22 12:13:19 ritsu sudo[1165]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 22 12:13:19 ritsu sudo[1165]: pam_unix(sudo:session): session closed for user root Apr 22 12:13:19 ritsu volumio[655]: info: Completed starting Core Plugins Apr 22 12:13:19 ritsu volumio[655]: info: ------------------------------------------- Apr 22 12:13:19 ritsu volumio[655]: info: ----- MyVolumio plugins startup ---- Apr 22 12:13:19 ritsu volumio[655]: info: ------------------------------------------- Apr 22 12:13:19 ritsu volumio[655]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 22 12:13:19 ritsu go-librespot[983]: time="2025-04-22T12:13:19-05:00" level=debug msg="handling transfer player command from d5d290541197a78b75b16d8eb345b6c16ee2ecd2" Apr 22 12:13:19 ritsu go-librespot[983]: time="2025-04-22T12:13:19-05:00" level=debug msg="resolved context of track" uri="spotify:user:ipickering2:collection" Apr 22 12:13:19 ritsu go-librespot[983]: time="2025-04-22T12:13:19-05:00" level=trace msg="fetched new page 0 with 281 items (list: 281)" uri="spotify:user:ipickering2:collection" Apr 22 12:13:19 ritsu go-librespot[983]: time="2025-04-22T12:13:19-05:00" level=debug msg="loading track (paused: false, position: -36294ms)" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:19 ritsu go-librespot[983]: time="2025-04-22T12:13:19-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 22 12:13:19 ritsu go-librespot[983]: time="2025-04-22T12:13:19-05:00" level=trace msg="emitting websocket event: will_play" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="selected format OGG_VORBIS_320 (b8f307d9caa6ddddd4a94d3e67a83bf16ce7d7ba)" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="requested aes key for file b8f307d9caa6ddddd4a94d3e67a83bf16ce7d7ba, gid: 6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:20 ritsu volumio[655]: (node:655) UnhandledPromiseRejectionWarning: TypeError: Cannot read property '0' of undefined Apr 22 12:13:20 ritsu volumio[655]: at PlayerStatusMonitor._PlayerStatusMonitor_parsePlayerStatusResult (/data/plugins/music_service/squeezelite_mc/dist/lib/PlayerStatusMonitor.js:180:37) Apr 22 12:13:20 ritsu volumio[655]: at PlayerStatusMonitor._PlayerStatusMonitor_getStatusAndEmit (/data/plugins/music_service/squeezelite_mc/dist/lib/PlayerStatusMonitor.js:118:129) Apr 22 12:13:20 ritsu volumio[655]: at runMicrotasks () Apr 22 12:13:20 ritsu volumio[655]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Apr 22 12:13:20 ritsu volumio[655]: at async PlayerStatusMonitor.start (/data/plugins/music_service/squeezelite_mc/dist/lib/PlayerStatusMonitor.js:47:9) Apr 22 12:13:20 ritsu volumio[655]: at async PlayerFinder. (/data/plugins/music_service/squeezelite_mc/dist/index.js:686:13) Apr 22 12:13:20 ritsu volumio[655]: (Use `node --trace-warnings ...` to show where the warning was created) Apr 22 12:13:20 ritsu volumio[655]: (node:655) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) Apr 22 12:13:20 ritsu volumio[655]: (node:655) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="fetched first chunk of 36, total size is 18568784 bytes" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:20 ritsu kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="created new output device" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=info msg="loaded track \"Upwards At 45 Degrees\" (paused: false, position: -36294ms, duration: 346346ms, prefetched: false)" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="fetched chunk 3/35, size: 524288" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="fetched chunk 1/35, size: 524288" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=trace msg="scheduling prefetch in 316s" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=trace msg="emitting websocket event: metadata" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=trace msg="emitting websocket event: active" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="sending successful reply for dealer request" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="fetched chunk 2/35, size: 524288" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=trace msg="emitting websocket event: playing" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=trace msg="closed output device because of stop command" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1324" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="put connect state inactive" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=trace msg="emitting websocket event: inactive" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=trace msg="emitting websocket event: stopped" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=error msg="failed receiving dealer message" error="failed to get reader: received close frame: status = StatusGoingAway and reason = \"\"" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.1.140:35924->104.154.127.247:4070: use of closed network connection" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="obtained new client token: AABmPHl2ZcVAAKcq77jZGXrKX1VbNPw2NoWWSc6TFid9yd1RxDLO/OySFnuWyZ4dfBmwjDmBL87u/VFLVRJwrgIZxhKVg1GPdaJfmrX3NG3S8cBMWcX0Ejqk2MBB0IMlD4ltwCxSBzR8pxQDiAjCg50QHVnLaiIMOE0bfdx1Y4LdcQhfeQeHKDIeZID3sbHoOXoCrBcDarwUAlDUS1H3CQns7Q05318i6rbxJnKTriGHRoi3qxK8vCLGQp5gZQ==" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=info msg="connected to ap-guc3.spotify.com:4070" Apr 22 12:13:20 ritsu go-librespot[983]: time="2025-04-22T12:13:20-05:00" level=debug msg="completed keyexchange" Apr 22 12:13:20 ritsu volumio[981]: ...................................++++ Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="completed challenge" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="authenticated as ipickering2" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="authenticated as ipickering2" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="dealer connection opened" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="restored session after logout, username: ipickering2" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="autoplay enabled: false" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="received connection id: OTZlMjg3NWMtODY2MS00NWIzLTkyMDItYjUxMzNmZmRiYmQ5K2RlYWxlcit0Y3A6Ly8wYWNiZDk5ZS5pcC5ndWMzLnNwb3RpZnkubmV0OjU3MDArNzE2OTYzOEJFRkUyMzU5QkUxRTY5MzQ4M0M5Nzk4ODREOEQ0NDY3RUJFNTdGODcxN0RENjUzMkUyMTQxMDdDMA==" Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="put connect state because NEW_DEVICE" Apr 22 12:13:21 ritsu volumio[655]: info: Initializing connection to go-librespot Websocket Apr 22 12:13:21 ritsu go-librespot[983]: time="2025-04-22T12:13:21-05:00" level=debug msg="new websocket client" Apr 22 12:13:21 ritsu volumio[655]: info: Connection to go-librespot Websocket established Apr 22 12:13:22 ritsu go-librespot[983]: time="2025-04-22T12:13:22-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 341" Apr 22 12:13:22 ritsu go-librespot[983]: time="2025-04-22T12:13:22-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 22 12:13:22 ritsu go-librespot[983]: time="2025-04-22T12:13:22-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 22 12:13:22 ritsu go-librespot[983]: time="2025-04-22T12:13:22-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1395" Apr 22 12:13:23 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 22 12:13:23 ritsu volumio[655]: info: Discovery: Getting this device information Apr 22 12:13:23 ritsu volumio[655]: info: CoreCommandRouter::volumioGetState Apr 22 12:13:23 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:23 ritsu volumio[655]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 22 12:13:23 ritsu volumio[655]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=debug msg="handling transfer player command from d5d290541197a78b75b16d8eb345b6c16ee2ecd2" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=debug msg="resolved context of track" uri="spotify:user:ipickering2:collection" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=trace msg="fetched new page 0 with 281 items (list: 281)" uri="spotify:user:ipickering2:collection" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=debug msg="loading track (paused: false, position: -33242ms)" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=trace msg="emitting websocket event: will_play" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=debug msg="selected format OGG_VORBIS_320 (b8f307d9caa6ddddd4a94d3e67a83bf16ce7d7ba)" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=debug msg="requested aes key for file b8f307d9caa6ddddd4a94d3e67a83bf16ce7d7ba, gid: 6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:24 ritsu volumio[655]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6AHkWeLTZa05X2VRr1fvLB","play_origin":"playlist"}} Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=debug msg="fetched first chunk of 36, total size is 18568784 bytes" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=debug msg="created new output device" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=info msg="loaded track \"Upwards At 45 Degrees\" (paused: false, position: -33242ms, duration: 346346ms, prefetched: false)" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:24 ritsu go-librespot[983]: time="2025-04-22T12:13:24-05:00" level=debug msg="fetched chunk 1/35, size: 524288" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=debug msg="fetched chunk 2/35, size: 524288" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:25 ritsu volumio[655]: info: Getting Spotify volume Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=trace msg="scheduling prefetch in 316s" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=trace msg="emitting websocket event: metadata" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=trace msg="emitting websocket event: active" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=debug msg="sending successful reply for dealer request" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=debug msg="fetched chunk 3/35, size: 524288" uri="spotify:track:6AHkWeLTZa05X2VRr1fvLB" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=trace msg="emitting websocket event: playing" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=trace msg="closed output device because of stop command" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=debug msg="put connect state inactive" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=trace msg="emitting websocket event: inactive" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=trace msg="emitting websocket event: stopped" Apr 22 12:13:25 ritsu volumio[655]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6AHkWeLTZa05X2VRr1fvLB","name":"Upwards At 45 Degrees","artist_names":["Julian Cope"],"album_name":"Jehovahkill","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02470d8899215a67563366e77f","position":-33242,"duration":346346,"release_date":"year:1992","track_number":5,"disc_number":1}} Apr 22 12:13:25 ritsu volumio[655]: SPOTIFY: received: {"type":"active","data":null} Apr 22 12:13:25 ritsu volumio[655]: info: Aligning Spotify Volume to Volumio Volume Apr 22 12:13:25 ritsu volumio[655]: info: CoreCommandRouter::volumioGetState Apr 22 12:13:25 ritsu volumio[655]: info: CorePlayQueue::getTrack 0 Apr 22 12:13:25 ritsu volumio[655]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6AHkWeLTZa05X2VRr1fvLB","play_origin":"playlist"}} Apr 22 12:13:25 ritsu volumio[655]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 22 12:13:25 ritsu volumio[655]: TypeError: Cannot read property 'service' of undefined Apr 22 12:13:25 ritsu volumio[655]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Apr 22 12:13:25 ritsu volumio[655]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Apr 22 12:13:25 ritsu volumio[655]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Apr 22 12:13:25 ritsu volumio[655]: at WebSocket.emit (events.js:315:20) Apr 22 12:13:25 ritsu volumio[655]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Apr 22 12:13:25 ritsu volumio[655]: at Receiver.emit (events.js:315:20) Apr 22 12:13:25 ritsu volumio[655]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Apr 22 12:13:25 ritsu volumio[655]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Apr 22 12:13:25 ritsu volumio[655]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Apr 22 12:13:25 ritsu volumio[655]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Apr 22 12:13:25 ritsu volumio[655]: at writeOrBuffer (internal/streams/writable.js:358:12) Apr 22 12:13:25 ritsu volumio[655]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Apr 22 12:13:25 ritsu volumio[655]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Apr 22 12:13:25 ritsu volumio[655]: at Socket.emit (events.js:315:20) Apr 22 12:13:25 ritsu volumio[655]: at addChunk (internal/streams/readable.js:309:12) Apr 22 12:13:25 ritsu volumio[655]: at readableAddChunk (internal/streams/readable.js:284:9) Apr 22 12:13:25 ritsu volumio[655]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=error msg="failed receiving dealer message" error="failed to get reader: received close frame: status = StatusGoingAway and reason = \"\"" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.1.140:55056->104.154.127.247:4070: use of closed network connection" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=debug msg="obtained new client token: AAAUFoB/G4Yi3sehQQMktGb5BMn1JGC49o4TQNKV5ulIa6tnu/cMwzQQbL1jMhVLsRvtMtrXt0+GCM6WNfTnAbB7i+FdImY5xXp7VCficCZiDujsJ4cYipAjiBNDygtdy4+MEJxFNCcMcsuu8iKCtqYYkl6emnlaUrPVHSEtjGhXidHVReeVp9TAzdATjBr+Bv/t/ic7IlGz/tKObaNq5QuIOENtJXXYLkQdODEhOvG6CbS9fCuN2nmkI2pROw==" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=info msg="connected to ap-guc3.spotify.com:4070" Apr 22 12:13:25 ritsu go-librespot[983]: time="2025-04-22T12:13:25-05:00" level=debug msg="completed keyexchange" Apr 22 12:13:25 ritsu sudo[1300]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-22 12:12 Apr 22 12:13:25 ritsu sudo[1300]: 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"