-- Logs begin at Sat 2024-10-19 14:34:41 CEST, end at Sat 2024-10-19 14:35:37 CEST. -- Oct 19 14:34:41 volumio kernel: Booting Linux on physical CPU 0x0 Oct 19 14:34:41 volumio kernel: Linux version 5.15.93-sunxi (root@thinkcentre) (arm-linux-gnueabihf-gcc (GNU Toolchain for the A-profile Architecture 8.3-2019.03 (arm-rel-8.36)) 8.3.0, GNU ld (GNU Toolchain for the A-profile Architecture 8.3-2019.03 (arm-rel-8.36)) 2.32.0.20190321) #trunk SMP Tue Jul 11 12:56:04 CEST 2023 Oct 19 14:34:41 volumio kernel: CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=50c5387d Oct 19 14:34:41 volumio kernel: CPU: div instructions available: patching division code Oct 19 14:34:41 volumio kernel: CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache Oct 19 14:34:41 volumio kernel: OF: fdt: Machine model: Xunlong Orange Pi One Oct 19 14:34:41 volumio kernel: Memory policy: Data cache writealloc Oct 19 14:34:41 volumio kernel: cma: Reserved 104 MiB at 0x59800000 Oct 19 14:34:41 volumio kernel: Zone ranges: Oct 19 14:34:41 volumio kernel: Normal [mem 0x0000000040000000-0x000000005fffffff] Oct 19 14:34:41 volumio kernel: HighMem empty Oct 19 14:34:41 volumio kernel: Movable zone start for each node Oct 19 14:34:41 volumio kernel: Early memory node ranges Oct 19 14:34:41 volumio kernel: node 0: [mem 0x0000000040000000-0x000000005fffffff] Oct 19 14:34:41 volumio kernel: Initmem setup node 0 [mem 0x0000000040000000-0x000000005fffffff] Oct 19 14:34:41 volumio kernel: psci: probing for conduit method from DT. Oct 19 14:34:41 volumio kernel: psci: Using PSCI v0.1 Function IDs from DT Oct 19 14:34:41 volumio kernel: percpu: Embedded 17 pages/cpu s38540 r8192 d22900 u69632 Oct 19 14:34:41 volumio kernel: pcpu-alloc: s38540 r8192 d22900 u69632 alloc=17*4096 Oct 19 14:34:41 volumio kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Oct 19 14:34:41 volumio kernel: Built 1 zonelists, mobility grouping on. Total pages: 129920 Oct 19 14:34:41 volumio kernel: Kernel command line: root=/dev/mmcblk0p2 rootwait rootfstype=ext4 splash plymouth.ignore-serial-consoles console=ttyS0,115200 console=tty1 hdmi.audio=EDID:0 disp.screen0_output_mode=1920x1080p60 consoleblank=0 loglevel=0 ubootpart=63c75005-01 ubootsource=mmc usb-storage.quirks=0x2537:0x1066:u,0x2537:0x1068:u imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh net.ifnames=0 hwver=orangepi sunxi_ve_mem_reserve=0 sunxi_g2d_mem_reserve=0 sunxi_fb_mem_reserve=16 cgroup_enable=memory swapaccount=1 Oct 19 14:34:41 volumio kernel: Unknown kernel command line parameters "splash ubootpart=63c75005-01 ubootsource=mmc imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh hwver=orangepi sunxi_ve_mem_reserve=0 sunxi_g2d_mem_reserve=0 sunxi_fb_mem_reserve=16 cgroup_enable=memory", will be passed to user space. Oct 19 14:34:41 volumio kernel: Dentry cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Oct 19 14:34:41 volumio kernel: Inode-cache hash table entries: 32768 (order: 5, 131072 bytes, linear) Oct 19 14:34:41 volumio kernel: mem auto-init: stack:off, heap alloc:on, heap free:off Oct 19 14:34:41 volumio kernel: Memory: 380924K/524288K available (9216K kernel code, 1510K rwdata, 3408K rodata, 1024K init, 326K bss, 36868K reserved, 106496K cma-reserved, 0K highmem) Oct 19 14:34:41 volumio kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Oct 19 14:34:41 volumio kernel: ftrace: allocating 44001 entries in 130 pages Oct 19 14:34:41 volumio kernel: ftrace: allocated 129 pages with 2 groups Oct 19 14:34:41 volumio kernel: trace event string verifier disabled Oct 19 14:34:41 volumio kernel: rcu: Hierarchical RCU implementation. Oct 19 14:34:41 volumio kernel: rcu: RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=4. Oct 19 14:34:41 volumio kernel: Rude variant of Tasks RCU enabled. Oct 19 14:34:41 volumio kernel: Tracing variant of Tasks RCU enabled. Oct 19 14:34:41 volumio kernel: rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. Oct 19 14:34:41 volumio kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 Oct 19 14:34:41 volumio kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Oct 19 14:34:41 volumio kernel: GIC: Using split EOI/Deactivate mode Oct 19 14:34:41 volumio kernel: clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns Oct 19 14:34:41 volumio kernel: arch_timer: cp15 timer(s) running at 24.00MHz (phys). Oct 19 14:34:41 volumio kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x588fe9dc0, max_idle_ns: 440795202592 ns Oct 19 14:34:41 volumio kernel: sched_clock: 56 bits at 24MHz, resolution 41ns, wraps every 4398046511097ns Oct 19 14:34:41 volumio kernel: Switching to timer-based delay loop, resolution 41ns Oct 19 14:34:41 volumio kernel: Console: colour dummy device 80x30 Oct 19 14:34:41 volumio kernel: printk: console [tty1] enabled Oct 19 14:34:41 volumio kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=96000) Oct 19 14:34:41 volumio kernel: pid_max: default: 32768 minimum: 301 Oct 19 14:34:41 volumio kernel: LSM: Security Framework initializing Oct 19 14:34:41 volumio kernel: Yama: becoming mindful. Oct 19 14:34:41 volumio kernel: AppArmor: AppArmor initialized Oct 19 14:34:41 volumio kernel: Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear) Oct 19 14:34:41 volumio kernel: Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear) Oct 19 14:34:41 volumio kernel: CPU: Testing write buffer coherency: ok Oct 19 14:34:41 volumio kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Oct 19 14:34:41 volumio kernel: Setting up static identity map for 0x40100000 - 0x40100054 Oct 19 14:34:41 volumio kernel: rcu: Hierarchical SRCU implementation. Oct 19 14:34:41 volumio kernel: smp: Bringing up secondary CPUs ... Oct 19 14:34:41 volumio kernel: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Oct 19 14:34:41 volumio kernel: CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Oct 19 14:34:41 volumio kernel: CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Oct 19 14:34:41 volumio kernel: smp: Brought up 1 node, 4 CPUs Oct 19 14:34:41 volumio kernel: SMP: Total of 4 processors activated (192.00 BogoMIPS). Oct 19 14:34:41 volumio kernel: CPU: All CPU(s) started in HYP mode. Oct 19 14:34:41 volumio kernel: CPU: Virtualization extensions available. Oct 19 14:34:41 volumio kernel: allocated 524288 bytes of page_ext Oct 19 14:34:41 volumio kernel: devtmpfs: initialized Oct 19 14:34:41 volumio kernel: VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5 Oct 19 14:34:41 volumio kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns Oct 19 14:34:41 volumio kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Oct 19 14:34:41 volumio kernel: pinctrl core: initialized pinctrl subsystem Oct 19 14:34:41 volumio kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Oct 19 14:34:41 volumio kernel: DMA: preallocated 256 KiB pool for atomic coherent allocations Oct 19 14:34:41 volumio kernel: audit: initializing netlink subsys (disabled) Oct 19 14:34:41 volumio kernel: audit: type=2000 audit(0.036:1): state=initialized audit_enabled=0 res=1 Oct 19 14:34:41 volumio kernel: thermal_sys: Registered thermal governor 'fair_share' Oct 19 14:34:41 volumio kernel: thermal_sys: Registered thermal governor 'bang_bang' Oct 19 14:34:41 volumio kernel: thermal_sys: Registered thermal governor 'step_wise' Oct 19 14:34:41 volumio kernel: cpuidle: using governor ladder Oct 19 14:34:41 volumio kernel: cpuidle: using governor menu Oct 19 14:34:41 volumio kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Oct 19 14:34:41 volumio kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Oct 19 14:34:41 volumio kernel: platform 1c0c000.lcd-controller: Fixing up cyclic dependency with 1100000.mixer Oct 19 14:34:41 volumio kernel: platform 1ee0000.hdmi: Fixing up cyclic dependency with 1c0c000.lcd-controller Oct 19 14:34:41 volumio kernel: platform connector: Fixing up cyclic dependency with 1ee0000.hdmi Oct 19 14:34:41 volumio kernel: cryptd: max_cpu_qlen set to 1000 Oct 19 14:34:41 volumio kernel: raid6: neonx8 gen() 777 MB/s Oct 19 14:34:41 volumio kernel: raid6: neonx8 xor() 573 MB/s Oct 19 14:34:41 volumio kernel: raid6: neonx4 gen() 831 MB/s Oct 19 14:34:41 volumio kernel: raid6: neonx4 xor() 629 MB/s Oct 19 14:34:41 volumio kernel: raid6: neonx2 gen() 915 MB/s Oct 19 14:34:41 volumio kernel: raid6: neonx2 xor() 652 MB/s Oct 19 14:34:41 volumio kernel: raid6: neonx1 gen() 815 MB/s Oct 19 14:34:41 volumio kernel: raid6: neonx1 xor() 565 MB/s Oct 19 14:34:41 volumio kernel: raid6: int32x8 gen() 303 MB/s Oct 19 14:34:41 volumio kernel: raid6: int32x8 xor() 180 MB/s Oct 19 14:34:41 volumio kernel: raid6: int32x4 gen() 354 MB/s Oct 19 14:34:41 volumio kernel: raid6: int32x4 xor() 205 MB/s Oct 19 14:34:41 volumio kernel: raid6: int32x2 gen() 399 MB/s Oct 19 14:34:41 volumio kernel: raid6: int32x2 xor() 213 MB/s Oct 19 14:34:41 volumio kernel: raid6: int32x1 gen() 402 MB/s Oct 19 14:34:41 volumio kernel: raid6: int32x1 xor() 192 MB/s Oct 19 14:34:41 volumio kernel: raid6: using algorithm neonx2 gen() 915 MB/s Oct 19 14:34:41 volumio kernel: raid6: .... xor() 652 MB/s, rmw enabled Oct 19 14:34:41 volumio kernel: raid6: using neon recovery algorithm Oct 19 14:34:41 volumio kernel: iommu: Default domain type: Translated Oct 19 14:34:41 volumio kernel: iommu: DMA domain TLB invalidation policy: strict mode Oct 19 14:34:41 volumio kernel: SCSI subsystem initialized Oct 19 14:34:41 volumio kernel: libata version 3.00 loaded. Oct 19 14:34:41 volumio kernel: usbcore: registered new interface driver usbfs Oct 19 14:34:41 volumio kernel: usbcore: registered new interface driver hub Oct 19 14:34:41 volumio kernel: usbcore: registered new device driver usb Oct 19 14:34:41 volumio kernel: mc: Linux media interface: v0.10 Oct 19 14:34:41 volumio kernel: videodev: Linux video capture interface: v2.00 Oct 19 14:34:41 volumio kernel: pps_core: LinuxPPS API ver. 1 registered Oct 19 14:34:41 volumio kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti Oct 19 14:34:41 volumio kernel: PTP clock support registered Oct 19 14:34:41 volumio kernel: Advanced Linux Sound Architecture Driver Initialized. Oct 19 14:34:41 volumio kernel: NetLabel: Initializing Oct 19 14:34:41 volumio kernel: NetLabel: domain hash size = 128 Oct 19 14:34:41 volumio kernel: NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO Oct 19 14:34:41 volumio kernel: NetLabel: unlabeled traffic allowed by default Oct 19 14:34:41 volumio kernel: clocksource: Switched to clocksource arch_sys_counter Oct 19 14:34:41 volumio kernel: VFS: Disk quotas dquot_6.6.0 Oct 19 14:34:41 volumio kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Oct 19 14:34:41 volumio kernel: AppArmor: AppArmor Filesystem Enabled Oct 19 14:34:41 volumio kernel: NET: Registered PF_INET protocol family Oct 19 14:34:41 volumio kernel: IP idents hash table entries: 8192 (order: 4, 65536 bytes, linear) Oct 19 14:34:41 volumio kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear) Oct 19 14:34:41 volumio kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Oct 19 14:34:41 volumio kernel: TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear) Oct 19 14:34:41 volumio kernel: TCP bind hash table entries: 4096 (order: 3, 32768 bytes, linear) Oct 19 14:34:41 volumio kernel: TCP: Hash tables configured (established 4096 bind 4096) Oct 19 14:34:41 volumio kernel: UDP hash table entries: 256 (order: 1, 8192 bytes, linear) Oct 19 14:34:41 volumio kernel: UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear) Oct 19 14:34:41 volumio kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Oct 19 14:34:41 volumio kernel: Trying to unpack rootfs image as initramfs... Oct 19 14:34:41 volumio kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 5 counters available Oct 19 14:34:41 volumio kernel: Initialise system trusted keyrings Oct 19 14:34:41 volumio kernel: Key type blacklist registered Oct 19 14:34:41 volumio kernel: workingset: timestamp_bits=14 max_order=17 bucket_order=3 Oct 19 14:34:41 volumio kernel: zbud: loaded Oct 19 14:34:41 volumio kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Oct 19 14:34:41 volumio kernel: fuse: init (API version 7.34) Oct 19 14:34:41 volumio kernel: integrity: Platform Keyring initialized Oct 19 14:34:41 volumio kernel: xor: measuring software checksum speed Oct 19 14:34:41 volumio kernel: arm4regs : 1300 MB/sec Oct 19 14:34:41 volumio kernel: 8regs : 896 MB/sec Oct 19 14:34:41 volumio kernel: 32regs : 848 MB/sec Oct 19 14:34:41 volumio kernel: neon : 1319 MB/sec Oct 19 14:34:41 volumio kernel: xor: using function: neon (1319 MB/sec) Oct 19 14:34:41 volumio kernel: Key type asymmetric registered Oct 19 14:34:41 volumio kernel: Asymmetric key parser 'x509' registered Oct 19 14:34:41 volumio kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 246) Oct 19 14:34:41 volumio kernel: io scheduler mq-deadline registered Oct 19 14:34:41 volumio kernel: io scheduler kyber registered Oct 19 14:34:41 volumio kernel: io scheduler bfq registered Oct 19 14:34:41 volumio kernel: sun8i-h3-pinctrl 1c20800.pinctrl: initialized sunXi PIO driver Oct 19 14:34:41 volumio kernel: sun8i-h3-r-pinctrl 1f02c00.pinctrl: initialized sunXi PIO driver Oct 19 14:34:41 volumio kernel: Serial: 8250/16550 driver, 8 ports, IRQ sharing disabled Oct 19 14:34:41 volumio kernel: sun8i-h3-pinctrl 1c20800.pinctrl: supply vcc-pa not found, using dummy regulator Oct 19 14:34:41 volumio kernel: printk: console [ttyS0] disabled Oct 19 14:34:41 volumio kernel: 1c28000.serial: ttyS0 at MMIO 0x1c28000 (irq = 50, base_baud = 1500000) is a 16550A Oct 19 14:34:41 volumio kernel: printk: console [ttyS0] enabled Oct 19 14:34:41 volumio kernel: brd: module loaded Oct 19 14:34:41 volumio kernel: loop: module loaded Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: IRQ eth_wake_irq not found Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: IRQ eth_lpi not found Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: supply phy not found, using dummy regulator Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: supply phy-io not found, using dummy regulator Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: PTP uses main clock Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: Current syscon value is not the default 148000 (expect 58000) Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: No HW DMA feature register supported Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: RX Checksum Offload Engine supported Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: COE Type 2 Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: TX Checksum insertion supported Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: Normal descriptors Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: Chain mode enabled Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: Found internal PHY node Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: Switch mux to internal PHY Oct 19 14:34:41 volumio kernel: dwmac-sun8i 1c30000.ethernet: Powering internal PHY Oct 19 14:34:41 volumio kernel: Freeing initrd memory: 15044K Oct 19 14:34:41 volumio kernel: ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver Oct 19 14:34:41 volumio kernel: ehci-platform: EHCI generic platform driver Oct 19 14:34:41 volumio kernel: ehci-platform 1c1a000.usb: EHCI Host Controller Oct 19 14:34:41 volumio kernel: ehci-platform 1c1a000.usb: new USB bus registered, assigned bus number 1 Oct 19 14:34:41 volumio kernel: ehci-platform 1c1a000.usb: irq 35, io mem 0x01c1a000 Oct 19 14:34:41 volumio kernel: ehci-platform 1c1a000.usb: USB 2.0 started, EHCI 1.00 Oct 19 14:34:41 volumio kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15 Oct 19 14:34:41 volumio kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Oct 19 14:34:41 volumio kernel: usb usb1: Product: EHCI Host Controller Oct 19 14:34:41 volumio kernel: usb usb1: Manufacturer: Linux 5.15.93-sunxi ehci_hcd Oct 19 14:34:41 volumio kernel: usb usb1: SerialNumber: 1c1a000.usb Oct 19 14:34:41 volumio kernel: hub 1-0:1.0: USB hub found Oct 19 14:34:41 volumio kernel: hub 1-0:1.0: 1 port detected Oct 19 14:34:41 volumio kernel: ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver Oct 19 14:34:41 volumio kernel: ohci-platform: OHCI generic platform driver Oct 19 14:34:41 volumio kernel: ohci-platform 1c1a400.usb: Generic Platform OHCI controller Oct 19 14:34:41 volumio kernel: ohci-platform 1c1a400.usb: new USB bus registered, assigned bus number 2 Oct 19 14:34:41 volumio kernel: ohci-platform 1c1a400.usb: irq 36, io mem 0x01c1a400 Oct 19 14:34:41 volumio kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 5.15 Oct 19 14:34:41 volumio kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Oct 19 14:34:41 volumio kernel: usb usb2: Product: Generic Platform OHCI controller Oct 19 14:34:41 volumio kernel: usb usb2: Manufacturer: Linux 5.15.93-sunxi ohci_hcd Oct 19 14:34:41 volumio kernel: usb usb2: SerialNumber: 1c1a400.usb Oct 19 14:34:41 volumio kernel: hub 2-0:1.0: USB hub found Oct 19 14:34:41 volumio kernel: hub 2-0:1.0: 1 port detected Oct 19 14:34:41 volumio kernel: usbcore: registered new interface driver usb-storage Oct 19 14:34:41 volumio kernel: sun6i-rtc 1f00000.rtc: registered as rtc0 Oct 19 14:34:41 volumio kernel: sun6i-rtc 1f00000.rtc: setting system clock to 2024-10-19T12:34:34 UTC (1729341274) Oct 19 14:34:41 volumio kernel: sun6i-rtc 1f00000.rtc: RTC enabled Oct 19 14:34:41 volumio kernel: i2c_dev: i2c /dev entries driver Oct 19 14:34:41 volumio kernel: sunxi-wdt 1c20ca0.watchdog: Watchdog enabled (timeout=16 sec, nowayout=0) Oct 19 14:34:41 volumio kernel: sun8i-h3-pinctrl 1c20800.pinctrl: supply vcc-pf not found, using dummy regulator Oct 19 14:34:41 volumio kernel: sun8i-h3-r-pinctrl 1f02c00.pinctrl: supply vcc-pl not found, using dummy regulator Oct 19 14:34:41 volumio kernel: ledtrig-cpu: registered to indicate activity on CPUs Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Set mod clock to 50000000 (50 Mhz) from 24000000 (24 Mhz) Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: will run requests pump with realtime priority Oct 19 14:34:41 volumio kernel: sunxi-mmc 1c0f000.mmc: Got CD GPIO Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: will run requests pump with realtime priority Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: will run requests pump with realtime priority Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: will run requests pump with realtime priority Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register cbc(aes) Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register ecb(aes) Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register cbc(des3_ede) Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register ecb(des3_ede) Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register md5 Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register sha1 Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register sha224 Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register sha256 Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register sha384 Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register sha512 Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: Register stdrng Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: TRNG not supported Oct 19 14:34:41 volumio kernel: sun8i-ce 1c15000.crypto: CryptoEngine Die ID 1 Oct 19 14:34:41 volumio kernel: hid: raw HID events driver (C) Jiri Kosina Oct 19 14:34:41 volumio kernel: usbcore: registered new interface driver usbhid Oct 19 14:34:41 volumio kernel: usbhid: USB HID core driver Oct 19 14:34:41 volumio kernel: Initializing XFRM netlink socket Oct 19 14:34:41 volumio kernel: NET: Registered PF_INET6 protocol family Oct 19 14:34:41 volumio kernel: sunxi-mmc 1c0f000.mmc: initialized, max. request size: 16384 KB Oct 19 14:34:41 volumio kernel: Segment Routing with IPv6 Oct 19 14:34:41 volumio kernel: In-situ OAM (IOAM) with IPv6 Oct 19 14:34:41 volumio kernel: NET: Registered PF_PACKET protocol family Oct 19 14:34:41 volumio kernel: NET: Registered PF_KEY protocol family Oct 19 14:34:41 volumio kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. Oct 19 14:34:41 volumio kernel: 8021q: 802.1Q VLAN Support v1.8 Oct 19 14:34:41 volumio kernel: Key type dns_resolver registered Oct 19 14:34:41 volumio kernel: Registering SWP/SWPB emulation handler Oct 19 14:34:41 volumio kernel: registered taskstats version 1 Oct 19 14:34:41 volumio kernel: Loading compiled-in X.509 certificates Oct 19 14:34:41 volumio kernel: mmc0: host does not support reading read-only switch, assuming write-enable Oct 19 14:34:41 volumio kernel: mmc0: new high speed SDHC card at address aaaa Oct 19 14:34:41 volumio kernel: mmcblk0: mmc0:aaaa SC16G 14.8 GiB Oct 19 14:34:41 volumio kernel: Loaded X.509 cert 'Build time autogenerated kernel key: 8f8e38801ad26e1c5752b0545ce65e141a715a7d' Oct 19 14:34:41 volumio kernel: mmcblk0: p1 p2 p3 Oct 19 14:34:41 volumio kernel: zswap: loaded using pool zstd/z3fold Oct 19 14:34:41 volumio kernel: Key type .fscrypt registered Oct 19 14:34:41 volumio kernel: Key type fscrypt-provisioning registered Oct 19 14:34:41 volumio kernel: Btrfs loaded, crc32c=crc32c-generic, zoned=no, fsverity=yes Oct 19 14:34:41 volumio kernel: Key type encrypted registered Oct 19 14:34:41 volumio kernel: AppArmor: AppArmor sha1 policy hashing enabled Oct 19 14:34:41 volumio kernel: sun8i-h3-pinctrl 1c20800.pinctrl: supply vcc-pg not found, using dummy regulator Oct 19 14:34:41 volumio kernel: sun4i-drm display-engine: bound 1100000.mixer (ops 0xc0aa3538) Oct 19 14:34:41 volumio kernel: sun4i-drm display-engine: bound 1c0c000.lcd-controller (ops 0xc0a9f46c) Oct 19 14:34:41 volumio kernel: sun8i-dw-hdmi 1ee0000.hdmi: supply hvcc not found, using dummy regulator Oct 19 14:34:41 volumio kernel: sun8i-dw-hdmi 1ee0000.hdmi: Detected HDMI TX controller v1.32a with HDCP (sun8i_dw_hdmi_phy) Oct 19 14:34:41 volumio kernel: sun8i-dw-hdmi 1ee0000.hdmi: registered DesignWare HDMI I2C bus driver Oct 19 14:34:41 volumio kernel: sun4i-drm display-engine: bound 1ee0000.hdmi (ops 0xc0aa2aec) Oct 19 14:34:41 volumio kernel: [drm] Initialized sun4i-drm 1.0.0 20150629 for display-engine on minor 0 Oct 19 14:34:41 volumio kernel: sun4i-drm display-engine: [drm] Cannot find any crtc or sizes Oct 19 14:34:41 volumio kernel: ehci-platform 1c1b000.usb: EHCI Host Controller Oct 19 14:34:41 volumio kernel: ehci-platform 1c1b000.usb: new USB bus registered, assigned bus number 3 Oct 19 14:34:41 volumio kernel: sun4i-drm display-engine: [drm] Cannot find any crtc or sizes Oct 19 14:34:41 volumio kernel: ehci-platform 1c1b000.usb: irq 37, io mem 0x01c1b000 Oct 19 14:34:41 volumio kernel: ehci-platform 1c1b000.usb: USB 2.0 started, EHCI 1.00 Oct 19 14:34:41 volumio kernel: usb usb3: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15 Oct 19 14:34:41 volumio kernel: usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Oct 19 14:34:41 volumio kernel: usb usb3: Product: EHCI Host Controller Oct 19 14:34:41 volumio kernel: usb usb3: Manufacturer: Linux 5.15.93-sunxi ehci_hcd Oct 19 14:34:41 volumio kernel: usb usb3: SerialNumber: 1c1b000.usb Oct 19 14:34:41 volumio kernel: hub 3-0:1.0: USB hub found Oct 19 14:34:41 volumio kernel: hub 3-0:1.0: 1 port detected Oct 19 14:34:41 volumio kernel: ehci-platform 1c1c000.usb: EHCI Host Controller Oct 19 14:34:41 volumio kernel: ehci-platform 1c1c000.usb: new USB bus registered, assigned bus number 4 Oct 19 14:34:41 volumio kernel: ehci-platform 1c1c000.usb: irq 39, io mem 0x01c1c000 Oct 19 14:34:41 volumio kernel: ehci-platform 1c1c000.usb: USB 2.0 started, EHCI 1.00 Oct 19 14:34:41 volumio kernel: usb usb4: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15 Oct 19 14:34:41 volumio kernel: usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Oct 19 14:34:41 volumio kernel: usb usb4: Product: EHCI Host Controller Oct 19 14:34:41 volumio kernel: usb usb4: Manufacturer: Linux 5.15.93-sunxi ehci_hcd Oct 19 14:34:41 volumio kernel: usb usb4: SerialNumber: 1c1c000.usb Oct 19 14:34:41 volumio kernel: hub 4-0:1.0: USB hub found Oct 19 14:34:41 volumio kernel: hub 4-0:1.0: 1 port detected Oct 19 14:34:41 volumio kernel: ehci-platform 1c1d000.usb: EHCI Host Controller Oct 19 14:34:41 volumio kernel: ehci-platform 1c1d000.usb: new USB bus registered, assigned bus number 5 Oct 19 14:34:41 volumio kernel: ehci-platform 1c1d000.usb: irq 41, io mem 0x01c1d000 Oct 19 14:34:41 volumio kernel: ehci-platform 1c1d000.usb: USB 2.0 started, EHCI 1.00 Oct 19 14:34:41 volumio kernel: usb usb5: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15 Oct 19 14:34:41 volumio kernel: usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Oct 19 14:34:41 volumio kernel: usb usb5: Product: EHCI Host Controller Oct 19 14:34:41 volumio kernel: usb usb5: Manufacturer: Linux 5.15.93-sunxi ehci_hcd Oct 19 14:34:41 volumio kernel: usb usb5: SerialNumber: 1c1d000.usb Oct 19 14:34:41 volumio kernel: hub 5-0:1.0: USB hub found Oct 19 14:34:41 volumio kernel: hub 5-0:1.0: 1 port detected Oct 19 14:34:41 volumio kernel: ohci-platform 1c1b400.usb: Generic Platform OHCI controller Oct 19 14:34:41 volumio kernel: ohci-platform 1c1b400.usb: new USB bus registered, assigned bus number 6 Oct 19 14:34:41 volumio kernel: ohci-platform 1c1b400.usb: irq 38, io mem 0x01c1b400 Oct 19 14:34:41 volumio kernel: usb usb6: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 5.15 Oct 19 14:34:41 volumio kernel: usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Oct 19 14:34:41 volumio kernel: usb usb6: Product: Generic Platform OHCI controller Oct 19 14:34:41 volumio kernel: usb usb6: Manufacturer: Linux 5.15.93-sunxi ohci_hcd Oct 19 14:34:41 volumio kernel: usb usb6: SerialNumber: 1c1b400.usb Oct 19 14:34:41 volumio kernel: hub 6-0:1.0: USB hub found Oct 19 14:34:41 volumio kernel: hub 6-0:1.0: 1 port detected Oct 19 14:34:41 volumio kernel: ohci-platform 1c1c400.usb: Generic Platform OHCI controller Oct 19 14:34:41 volumio kernel: ohci-platform 1c1c400.usb: new USB bus registered, assigned bus number 7 Oct 19 14:34:41 volumio kernel: ohci-platform 1c1c400.usb: irq 40, io mem 0x01c1c400 Oct 19 14:34:41 volumio kernel: usb usb7: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 5.15 Oct 19 14:34:41 volumio kernel: usb usb7: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Oct 19 14:34:41 volumio kernel: usb usb7: Product: Generic Platform OHCI controller Oct 19 14:34:41 volumio kernel: usb usb7: Manufacturer: Linux 5.15.93-sunxi ohci_hcd Oct 19 14:34:41 volumio kernel: usb usb7: SerialNumber: 1c1c400.usb Oct 19 14:34:41 volumio kernel: hub 7-0:1.0: USB hub found Oct 19 14:34:41 volumio kernel: hub 7-0:1.0: 1 port detected Oct 19 14:34:41 volumio kernel: ohci-platform 1c1d400.usb: Generic Platform OHCI controller Oct 19 14:34:41 volumio kernel: ohci-platform 1c1d400.usb: new USB bus registered, assigned bus number 8 Oct 19 14:34:41 volumio kernel: ohci-platform 1c1d400.usb: irq 42, io mem 0x01c1d400 Oct 19 14:34:41 volumio kernel: usb usb8: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 5.15 Oct 19 14:34:41 volumio kernel: usb usb8: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Oct 19 14:34:41 volumio kernel: usb usb8: Product: Generic Platform OHCI controller Oct 19 14:34:41 volumio kernel: usb usb8: Manufacturer: Linux 5.15.93-sunxi ohci_hcd Oct 19 14:34:41 volumio kernel: usb usb8: SerialNumber: 1c1d400.usb Oct 19 14:34:41 volumio kernel: hub 8-0:1.0: USB hub found Oct 19 14:34:41 volumio kernel: hub 8-0:1.0: 1 port detected Oct 19 14:34:41 volumio kernel: of_cfs_init Oct 19 14:34:41 volumio kernel: of_cfs_init: OK Oct 19 14:34:41 volumio kernel: ALSA device list: Oct 19 14:34:41 volumio kernel: No soundcards found. Oct 19 14:34:41 volumio kernel: Freeing unused kernel image (initmem) memory: 1024K Oct 19 14:34:41 volumio kernel: Run /init as init process Oct 19 14:34:41 volumio kernel: with arguments: Oct 19 14:34:41 volumio kernel: /init Oct 19 14:34:41 volumio kernel: splash Oct 19 14:34:41 volumio kernel: with environment: Oct 19 14:34:41 volumio kernel: HOME=/ Oct 19 14:34:41 volumio kernel: TERM=linux Oct 19 14:34:41 volumio kernel: ubootpart=63c75005-01 Oct 19 14:34:41 volumio kernel: ubootsource=mmc Oct 19 14:34:41 volumio kernel: imgpart=/dev/mmcblk0p2 Oct 19 14:34:41 volumio kernel: imgfile=/volumio_current.sqsh Oct 19 14:34:41 volumio kernel: hwver=orangepi Oct 19 14:34:41 volumio kernel: sunxi_ve_mem_reserve=0 Oct 19 14:34:41 volumio kernel: sunxi_g2d_mem_reserve=0 Oct 19 14:34:41 volumio kernel: sunxi_fb_mem_reserve=16 Oct 19 14:34:41 volumio kernel: cgroup_enable=memory Oct 19 14:34:41 volumio kernel: usb 3-1: new high-speed USB device number 2 using ehci-platform Oct 19 14:34:41 volumio kernel: usb 3-1: New USB device found, idVendor=7392, idProduct=7811, bcdDevice= 2.00 Oct 19 14:34:41 volumio kernel: usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Oct 19 14:34:41 volumio kernel: usb 3-1: Product: 802.11n WLAN Adapter Oct 19 14:34:41 volumio kernel: usb 3-1: Manufacturer: Realtek Oct 19 14:34:41 volumio kernel: usb 3-1: SerialNumber: 00e04c000001 Oct 19 14:34:41 volumio kernel: input: r_gpio_keys as /devices/platform/r_gpio_keys/input/input0 Oct 19 14:34:41 volumio kernel: usb_phy_generic usb_phy_generic.3.auto: supply vcc not found, using dummy regulator Oct 19 14:34:41 volumio kernel: usb_phy_generic usb_phy_generic.3.auto: dummy supplies not allowed for exclusive requests Oct 19 14:34:41 volumio kernel: musb-hdrc musb-hdrc.4.auto: MUSB HDRC host driver Oct 19 14:34:41 volumio kernel: musb-hdrc musb-hdrc.4.auto: new USB bus registered, assigned bus number 9 Oct 19 14:34:41 volumio kernel: usb usb9: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15 Oct 19 14:34:41 volumio kernel: usb usb9: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Oct 19 14:34:41 volumio kernel: usb usb9: Product: MUSB HDRC host driver Oct 19 14:34:41 volumio kernel: usb usb9: Manufacturer: Linux 5.15.93-sunxi musb-hcd Oct 19 14:34:41 volumio kernel: usb usb9: SerialNumber: musb-hdrc.4.auto Oct 19 14:34:41 volumio kernel: hub 9-0:1.0: USB hub found Oct 19 14:34:41 volumio kernel: hub 9-0:1.0: 1 port detected Oct 19 14:34:41 volumio kernel: lima 1c40000.gpu: gp - mali400 version major 1 minor 1 Oct 19 14:34:41 volumio kernel: lima 1c40000.gpu: pp0 - mali400 version major 1 minor 1 Oct 19 14:34:41 volumio kernel: lima 1c40000.gpu: pp1 - mali400 version major 1 minor 1 Oct 19 14:34:41 volumio kernel: lima 1c40000.gpu: l2 cache 64K, 4-way, 64byte cache line, 64bit external bus Oct 19 14:34:41 volumio kernel: lima 1c40000.gpu: bus rate = 200000000 Oct 19 14:34:41 volumio kernel: lima 1c40000.gpu: mod rate = 297000000 Oct 19 14:34:41 volumio kernel: lima 1c40000.gpu: dev_pm_opp_set_regulators: no regulator (mali) found: -19 Oct 19 14:34:41 volumio kernel: lima 1c40000.gpu: Failed to register cooling device Oct 19 14:34:41 volumio kernel: [drm] Initialized lima 1.2.0 20200215 for 1c40000.gpu on minor 1 Oct 19 14:34:41 volumio kernel: EXT4-fs (mmcblk0p2): recovery complete Oct 19 14:34:41 volumio kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none. Oct 19 14:34:41 volumio kernel: loop0: detected capacity change from 0 to 823560 Oct 19 14:34:41 volumio kernel: EXT4-fs (mmcblk0p3): recovery complete Oct 19 14:34:41 volumio kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none. Oct 19 14:34:41 volumio kernel: ext4 filesystem being mounted at /mnt/ext supports timestamps until 2038 (0x7fffffff) Oct 19 14:34:41 volumio systemd[1]: Inserted module 'autofs4' Oct 19 14:34:41 volumio 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) Oct 19 14:34:41 volumio systemd[1]: Detected architecture arm. Oct 19 14:34:41 volumio systemd[1]: Set hostname to . Oct 19 14:34:41 volumio 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. Oct 19 14:34:41 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Oct 19 14:34:41 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Oct 19 14:34:41 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Oct 19 14:34:41 volumio systemd[1]: Started Forward Password Requests to Wall Directory Watch. Oct 19 14:34:41 volumio systemd[1]: Listening on Journal Socket (/dev/log). Oct 19 14:34:41 volumio systemd[1]: Listening on initctl Compatibility Named Pipe. Oct 19 14:34:41 volumio systemd[1]: Created slice system-serial\x2dgetty.slice. Oct 19 14:34:41 volumio systemd[1]: Created slice User and Session Slice. Oct 19 14:34:41 volumio systemd[1]: Listening on fsck to fsckd communication Socket. Oct 19 14:34:41 volumio systemd-journald[424]: Journal started Oct 19 14:34:41 volumio systemd-journald[424]: Runtime journal (/run/log/journal/85c5a82949781d2451356fb26533b658) is 3.7M, max 30.0M, 26.2M free. Oct 19 14:34:41 volumio kernel: RPC: Registered named UNIX socket transport module. Oct 19 14:34:41 volumio kernel: RPC: Registered udp transport module. Oct 19 14:34:41 volumio kernel: RPC: Registered tcp transport module. Oct 19 14:34:41 volumio kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Oct 19 14:34:41 volumio volumio[430]: 512 MB or less RAM Detected, need to enable swap Oct 19 14:34:41 volumio fake-hwclock[434]: Current system time: 2024-10-19 12:34:41 Oct 19 14:34:41 volumio fake-hwclock[434]: fake-hwclock saved clock information is in the past: 2024-10-19 12:34:22 Oct 19 14:34:41 volumio fake-hwclock[434]: To set system time to this saved clock anyway, use "force" Oct 19 14:34:41 volumio systemd[1]: Mounted RPC Pipe File System. Oct 19 14:34:41 volumio systemd[1]: Mounted Kernel Configuration File System. Oct 19 14:34:41 volumio systemd[1]: Started Create System Users. Oct 19 14:34:41 volumio systemd[1]: Starting Create Static Device Nodes in /dev... Oct 19 14:34:41 volumio systemd[1]: Started Apply Kernel Variables. Oct 19 14:34:41 volumio volumio[430]: Enabling Swap Oct 19 14:34:41 volumio kernel: ext4 filesystem being mounted at /swap supports timestamps until 2038 (0x7fffffff) Oct 19 14:34:41 volumio systemd[1]: Started Create Static Device Nodes in /dev. Oct 19 14:34:41 volumio volumio[430]: Setting swappiness to 40 Oct 19 14:34:41 volumio kernel: Adding 524260k swap on /swap/swapfile. Priority:-2 extents:6 across:7591932k SSFS Oct 19 14:34:41 volumio systemd[1]: Started udev Coldplug all Devices. Oct 19 14:34:41 volumio volumio[430]: vm.swappiness = 40 Oct 19 14:34:41 volumio systemd[1]: Starting Helper to synchronize boot up for ifupdown... Oct 19 14:34:41 volumio systemd[1]: Reached target Local File Systems (Pre). Oct 19 14:34:41 volumio systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Oct 19 14:34:41 volumio systemd[1]: Mounting /var/log... Oct 19 14:34:42 volumio systemd[1]: Mounting /var/spool/cups... Oct 19 14:34:42 volumio systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Oct 19 14:34:42 volumio systemd[1]: Mounting /tmp... Oct 19 14:34:42 volumio systemd[1]: Starting udev Kernel Device Manager... Oct 19 14:34:42 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 19 14:34:42 volumio systemd[1]: Started Helper to synchronize boot up for ifupdown. Oct 19 14:34:42 volumio systemd[1]: Mounted /var/log. Oct 19 14:34:42 volumio systemd[1]: Mounted /var/spool/cups. Oct 19 14:34:42 volumio systemd[1]: Mounted /tmp. Oct 19 14:34:42 volumio systemd[1]: Mounting /var/spool/cups/tmp... Oct 19 14:34:42 volumio systemd[1]: Starting Flush Journal to Persistent Storage... Oct 19 14:34:42 volumio systemd[1]: Mounted /var/spool/cups/tmp. Oct 19 14:34:42 volumio systemd-udevd[466]: Network interface NamePolicy= disabled on kernel command line, ignoring. Oct 19 14:34:42 volumio systemd-journald[424]: Runtime journal (/run/log/journal/85c5a82949781d2451356fb26533b658) is 3.7M, max 30.0M, 26.2M free. Oct 19 14:34:42 volumio systemd[1]: Started udev Kernel Device Manager. Oct 19 14:34:42 volumio systemd[1]: Started Flush Journal to Persistent Storage. Oct 19 14:34:42 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Oct 19 14:34:42 volumio systemd[1]: Starting Show Plymouth Boot Screen... Oct 19 14:34:42 volumio kernel: random: systemd-journal: uninitialized urandom read (16 bytes read) Oct 19 14:34:42 volumio kernel: random: systemd-journal: uninitialized urandom read (16 bytes read) Oct 19 14:34:42 volumio systemd[1]: plymouth-start.service: Succeeded. Oct 19 14:34:42 volumio systemd[1]: Started Show Plymouth Boot Screen. Oct 19 14:34:42 volumio systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Oct 19 14:34:42 volumio systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Oct 19 14:34:42 volumio systemd[1]: Reached target Local Encrypted Volumes. Oct 19 14:34:42 volumio systemd[1]: Reached target Paths. Oct 19 14:34:42 volumio kernel: core: _opp_supported_by_regulators: OPP minuV: 1320000 maxuV: 1320000, not supported by regulator Oct 19 14:34:42 volumio kernel: cpu cpu0: _opp_add: OPP not supported by regulators (1104000000) Oct 19 14:34:42 volumio kernel: core: _opp_supported_by_regulators: OPP minuV: 1320000 maxuV: 1320000, not supported by regulator Oct 19 14:34:42 volumio kernel: cpu cpu0: _opp_add: OPP not supported by regulators (1200000000) Oct 19 14:34:42 volumio kernel: core: _opp_supported_by_regulators: OPP minuV: 1340000 maxuV: 1340000, not supported by regulator Oct 19 14:34:42 volumio kernel: cpu cpu0: _opp_add: OPP not supported by regulators (1296000000) Oct 19 14:34:42 volumio kernel: core: _opp_supported_by_regulators: OPP minuV: 1400000 maxuV: 1400000, not supported by regulator Oct 19 14:34:42 volumio kernel: cpu cpu0: _opp_add: OPP not supported by regulators (1368000000) Oct 19 14:34:42 volumio kernel: thermal thermal_zone0: binding zone cpu_thermal with cdev cpufreq-cpu0 failed:-22 Oct 19 14:34:42 volumio kernel: sunxi_cedrus: module is from the staging directory, the quality is unknown, you have been warned. Oct 19 14:34:42 volumio kernel: cedrus 1c0e000.video-codec: Device registered as /dev/video0 Oct 19 14:34:42 volumio systemd-udevd[481]: Using default interface naming scheme 'v240'. Oct 19 14:34:43 volumio kernel: debugfs: File 'Capture' in directory 'dapm' already present! Oct 19 14:34:43 volumio systemd-udevd[481]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Oct 19 14:34:43 volumio systemd-udevd[481]: link_config: could not get ethtool features for eth0 Oct 19 14:34:43 volumio systemd-udevd[481]: Could not set offload features of eth0: Device or resource busy Oct 19 14:34:43 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Oct 19 14:34:43 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Oct 19 14:34:43 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Oct 19 14:34:43 volumio kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Oct 19 14:34:43 volumio kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Oct 19 14:34:43 volumio kernel: platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 Oct 19 14:34:43 volumio kernel: platform regulatory.0: Falling back to sysfs fallback for: regulatory.db Oct 19 14:34:43 volumio systemd-udevd[470]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Oct 19 14:34:43 volumio kernel: cfg80211: failed to load regulatory.db Oct 19 14:34:43 volumio systemd-udevd[471]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 19 14:34:43 volumio kernel: rtl8192cu: Chip version 0x10 Oct 19 14:34:44 volumio kernel: rtl8192cu: Board Type 0 Oct 19 14:34:44 volumio kernel: rtl_usb: rx_max_size 15360, rx_urb_num 8, in_ep 1 Oct 19 14:34:44 volumio kernel: rtl8192cu: Loading firmware rtlwifi/rtl8192cufw_TMSC.bin Oct 19 14:34:44 volumio kernel: ieee80211 phy0: Selected rate control algorithm 'rtl_rc' Oct 19 14:34:44 volumio kernel: usbcore: registered new interface driver rtl8192cu Oct 19 14:34:44 volumio systemd-udevd[475]: Using default interface naming scheme 'v240'. Oct 19 14:34:44 volumio systemd-udevd[475]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Oct 19 14:34:44 volumio systemd[1]: Found device /dev/mmcblk0p1. Oct 19 14:34:44 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Oct 19 14:34:44 volumio systemd[1]: Found device /dev/ttyS0. Oct 19 14:34:44 volumio systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Oct 19 14:34:44 volumio systemd[1]: Condition check resulted in EW-7811Un 802.11n Wireless Adapter [Realtek RTL8188CUS] being skipped. Oct 19 14:34:44 volumio systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Oct 19 14:34:44 volumio systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Oct 19 14:34:44 volumio systemd[1]: Starting Show Plymouth Boot Screen... Oct 19 14:34:44 volumio systemd[1]: Condition check resulted in Huge Pages File System being skipped. Oct 19 14:34:44 volumio systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Oct 19 14:34:44 volumio systemd[1]: Starting File System Check on /dev/mmcblk0p1... Oct 19 14:34:44 volumio systemd[1]: Starting Load/Save RF Kill Switch Status... Oct 19 14:34:44 volumio systemd[1]: plymouth-start.service: Succeeded. Oct 19 14:34:44 volumio systemd[1]: Started Show Plymouth Boot Screen. Oct 19 14:34:44 volumio systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Oct 19 14:34:44 volumio systemd[1]: Started File System Check Daemon to report status. Oct 19 14:34:44 volumio systemd[1]: Started Load/Save RF Kill Switch Status. Oct 19 14:34:45 volumio systemd-fsck[683]: fsck.fat 4.1 (2017-01-24) Oct 19 14:34:45 volumio systemd-fsck[683]: /dev/mmcblk0p1: 255 files, 16528/30651 clusters Oct 19 14:34:45 volumio systemd[1]: Started File System Check on /dev/mmcblk0p1. Oct 19 14:34:45 volumio systemd[1]: Mounting /boot... Oct 19 14:34:45 volumio systemd[1]: Mounted /boot. Oct 19 14:34:45 volumio systemd[1]: Reached target Local File Systems. Oct 19 14:34:45 volumio systemd[1]: Started ifup for eth0. Oct 19 14:34:45 volumio systemd[1]: Starting Raise network interfaces... Oct 19 14:34:45 volumio systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Oct 19 14:34:45 volumio systemd[1]: Started ifup for wlan0. Oct 19 14:34:45 volumio systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Oct 19 14:34:45 volumio systemd[1]: Starting Preprocess NFS configuration... Oct 19 14:34:45 volumio systemd[1]: Starting Create Volatile Files and Directories... Oct 19 14:34:45 volumio systemd[1]: Received SIGRTMIN+20 from PID 329 (plymouthd). Oct 19 14:34:45 volumio systemd[1]: plymouth-read-write.service: Succeeded. Oct 19 14:34:45 volumio systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Oct 19 14:34:45 volumio systemd[1]: nfs-config.service: Succeeded. Oct 19 14:34:45 volumio systemd[1]: Started Preprocess NFS configuration. Oct 19 14:34:45 volumio systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Oct 19 14:34:45 volumio systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Oct 19 14:34:45 volumio systemd[1]: Reached target NFS client services. Oct 19 14:34:45 volumio systemd[1]: Started Create Volatile Files and Directories. Oct 19 14:34:45 volumio systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Oct 19 14:34:45 volumio systemd[1]: Starting Update UTMP about System Boot/Shutdown... Oct 19 14:34:45 volumio systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Oct 19 14:34:45 volumio systemd[1]: Starting RPC bind portmap service... Oct 19 14:34:45 volumio kernel: rtl8192cu: MAC auto ON okay! Oct 19 14:34:45 volumio systemd[1]: Started Update UTMP about System Boot/Shutdown. Oct 19 14:34:45 volumio systemd[1]: Reached target System Initialization. Oct 19 14:34:45 volumio systemd[1]: Listening on triggerhappy.socket. Oct 19 14:34:45 volumio systemd[1]: Started Daily Cleanup of Temporary Directories. Oct 19 14:34:45 volumio kernel: rtl8192cu: Tx queue select: 0x05 Oct 19 14:34:45 volumio systemd[1]: Listening on D-Bus System Message Bus Socket. Oct 19 14:34:45 volumio systemd[1]: Started Daily apt download activities. Oct 19 14:34:45 volumio systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Oct 19 14:34:45 volumio systemd[1]: Reached target Sockets. Oct 19 14:34:45 volumio systemd[1]: Reached target Basic System. Oct 19 14:34:45 volumio systemd[1]: Started Volumio Iptables Module. Oct 19 14:34:45 volumio systemd[1]: Starting Wireless Services... Oct 19 14:34:45 volumio systemd[1]: Started Volumio Log Rotation Service. Oct 19 14:34:45 volumio systemd[1]: Started Manage Sound Card State (restore and store). Oct 19 14:34:45 volumio alsactl[771]: alsactl 1.1.8 daemon started Oct 19 14:34:45 volumio systemd[1]: Starting Save/Restore Sound Card State... Oct 19 14:34:45 volumio systemd[1]: Started D-Bus System Message Bus. Oct 19 14:34:45 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Oct 19 14:34:45 volumio systemd[1]: Starting Login Service... Oct 19 14:34:45 volumio systemd[1]: Starting triggerhappy global hotkey daemon... Oct 19 14:34:45 volumio systemd[1]: Started volumio-remote-updater.service. Oct 19 14:34:46 volumio systemd[1]: Starting WPA supplicant... Oct 19 14:34:46 volumio systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Oct 19 14:34:46 volumio systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Oct 19 14:34:46 volumio systemd[1]: Starting DHCP Client Daemon... Oct 19 14:34:46 volumio systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Oct 19 14:34:46 volumio systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Oct 19 14:34:46 volumio systemd[1]: Started Daily apt upgrade and clean activities. Oct 19 14:34:46 volumio systemd[1]: Reached target Timers. Oct 19 14:34:46 volumio kernel: dwmac-sun8i 1c30000.ethernet eth0: PHY [0.1:01] driver [Generic PHY] (irq=POLL) Oct 19 14:34:46 volumio kernel: dwmac-sun8i 1c30000.ethernet eth0: Register MEM_TYPE_PAGE_POOL RxQ-0 Oct 19 14:34:46 volumio kernel: dwmac-sun8i 1c30000.ethernet eth0: No Safety Features support found Oct 19 14:34:46 volumio kernel: dwmac-sun8i 1c30000.ethernet eth0: No MAC Management Counters available Oct 19 14:34:46 volumio kernel: dwmac-sun8i 1c30000.ethernet eth0: PTP not supported by HW Oct 19 14:34:46 volumio kernel: dwmac-sun8i 1c30000.ethernet eth0: configuring for phy/mii link mode Oct 19 14:34:46 volumio sh[691]: eth0: waiting for carrier Oct 19 14:34:46 volumio dhcpcd[739]: eth0: waiting for carrier Oct 19 14:34:46 volumio sh[691]: eth0: carrier acquired Oct 19 14:34:46 volumio dhcpcd[739]: eth0: carrier acquired Oct 19 14:34:46 volumio sh[691]: DUID 00:01:00:01:2c:c6:73:4a:02:81:05:01:dd:24 Oct 19 14:34:46 volumio sh[691]: eth0: IAID 05:01:dd:24 Oct 19 14:34:46 volumio dhcpcd[739]: DUID 00:01:00:01:2c:c6:73:4a:02:81:05:01:dd:24 Oct 19 14:34:46 volumio dhcpcd[739]: eth0: IAID 05:01:dd:24 Oct 19 14:34:46 volumio sh[691]: eth0: adding address fe80::4bac:7621:83fe:eb09 Oct 19 14:34:46 volumio sh[691]: ipv6_addaddr1: Permission denied Oct 19 14:34:46 volumio sh[691]: eth0: carrier lost Oct 19 14:34:46 volumio dhcpcd[739]: eth0: adding address fe80::4bac:7621:83fe:eb09 Oct 19 14:34:46 volumio dhcpcd[739]: ipv6_addaddr1: Permission denied Oct 19 14:34:46 volumio dhcpcd[739]: eth0: carrier lost Oct 19 14:34:46 volumio thd[784]: Unable to parse trigger line: Oct 19 14:34:46 volumio thd[784]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Oct 19 14:34:46 volumio thd[784]: Unable to parse trigger line: Oct 19 14:34:46 volumio thd[784]: Unable to parse trigger line: Oct 19 14:34:46 volumio thd[784]: Unable to parse trigger line: Oct 19 14:34:46 volumio thd[784]: Unable to parse trigger line: Oct 19 14:34:46 volumio thd[784]: Unable to parse trigger line: Oct 19 14:34:46 volumio thd[784]: Unable to parse trigger line: Oct 19 14:34:46 volumio thd[784]: Found socket passed from systemd Oct 19 14:34:46 volumio dhcpcd[792]: cat: /run/dhcpcd/resolv.conf.eth0.link: No such file or directory Oct 19 14:34:46 volumio dhcpcd[792]: no interfaces have a carrier Oct 19 14:34:46 volumio dhcpcd[792]: no interfaces have a carrier Oct 19 14:34:46 volumio dhcpcd[792]: forked to background, child pid 854 Oct 19 14:34:46 volumio dhcpcd[792]: forked to background, child pid 854 Oct 19 14:34:46 volumio dhcpcd[854]: eth0: waiting for carrier Oct 19 14:34:46 volumio dhcpcd[854]: wlan0: waiting for carrier Oct 19 14:34:46 volumio dhcpcd[854]: wlan0: carrier acquired Oct 19 14:34:46 volumio dhcpcd[854]: DUID 00:01:00:01:2c:c6:73:4a:02:81:05:01:dd:24 Oct 19 14:34:46 volumio dhcpcd[854]: wlan0: IAID 38:28:a0:cd Oct 19 14:34:46 volumio dhcpcd[854]: wlan0: adding address fe80::3435:b893:8780:b1e6 Oct 19 14:34:46 volumio dhcpcd[854]: ipv6_addaddr1: Permission denied Oct 19 14:34:46 volumio dhcpcd[854]: eth0: carrier acquired Oct 19 14:34:46 volumio dhcpcd[854]: eth0: IAID 05:01:dd:24 Oct 19 14:34:46 volumio dhcpcd[854]: eth0: adding address fe80::4bac:7621:83fe:eb09 Oct 19 14:34:46 volumio dhcpcd[854]: ipv6_addaddr1: Permission denied Oct 19 14:34:46 volumio dhcpcd[854]: wlan0: carrier lost Oct 19 14:34:46 volumio systemd-logind[783]: New seat seat0. Oct 19 14:34:46 volumio dhcpcd[854]: eth0: carrier lost Oct 19 14:34:46 volumio systemd-logind[783]: Watching system buttons on /dev/input/event0 (r_gpio_keys) Oct 19 14:34:46 volumio avahi-daemon[791]: Found user 'avahi' (UID 111) and group 'avahi' (GID 113). Oct 19 14:34:46 volumio avahi-daemon[791]: Successfully dropped root privileges. Oct 19 14:34:46 volumio avahi-daemon[791]: avahi-daemon 0.7 starting up. Oct 19 14:34:47 volumio haveged[746]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.3.0 CTV); collect: 128K Oct 19 14:34:47 volumio haveged[746]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 12/40; sz: 15012/57848 Oct 19 14:34:47 volumio haveged[746]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99884 Oct 19 14:34:47 volumio haveged[746]: haveged: fills: 0, generated: 0 Oct 19 14:34:47 volumio systemd[1]: Started Login Service. Oct 19 14:34:47 volumio systemd[1]: Started RPC bind portmap service. Oct 19 14:34:47 volumio systemd[1]: Started triggerhappy global hotkey daemon. Oct 19 14:34:47 volumio avahi-daemon[791]: Successfully called chroot(). Oct 19 14:34:47 volumio avahi-daemon[791]: Successfully dropped remaining capabilities. Oct 19 14:34:47 volumio systemd[1]: Started Save/Restore Sound Card State. Oct 19 14:34:47 volumio systemd[1]: Started DHCP Client Daemon. Oct 19 14:34:47 volumio avahi-daemon[791]: No service file found in /etc/avahi/services. Oct 19 14:34:47 volumio avahi-daemon[791]: Network interface enumeration completed. Oct 19 14:34:47 volumio avahi-daemon[791]: Server startup complete. Host name is volumio.local. Local service cookie is 2405396096. Oct 19 14:34:47 volumio systemd[1]: Started Avahi mDNS/DNS-SD Stack. Oct 19 14:34:47 volumio systemd[1]: Reached target Sound Card. Oct 19 14:34:47 volumio systemd[1]: Reached target Remote File Systems (Pre). Oct 19 14:34:47 volumio systemd[1]: Reached target Remote File Systems. Oct 19 14:34:47 volumio systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Oct 19 14:34:47 volumio systemd[1]: Reached target RPC Port Mapper. Oct 19 14:34:47 volumio sh[694]: wlan0=wlan0 Oct 19 14:34:47 volumio systemd[1]: Started WPA supplicant. Oct 19 14:34:47 volumio wpa_supplicant[787]: Successfully initialized wpa_supplicant Oct 19 14:34:47 volumio systemd[1]: iptables.service: Succeeded. Oct 19 14:34:47 volumio systemd[1]: Started Raise network interfaces. Oct 19 14:34:47 volumio systemd[1]: Reached target Network. Oct 19 14:34:48 volumio systemd[1]: Starting Permit User Sessions... Oct 19 14:34:48 volumio systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Oct 19 14:34:48 volumio systemd[1]: Starting Network Time Service... Oct 19 14:34:48 volumio systemd[1]: Reached target Network is Online. Oct 19 14:34:48 volumio systemd[1]: Starting /etc/rc.local Compatibility... Oct 19 14:34:48 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 19 14:34:48 volumio systemd[1]: Starting Samba NMB Daemon... Oct 19 14:34:48 volumio systemd[1]: Starting LSB: Brings up/down network automatically... Oct 19 14:34:48 volumio systemd[1]: Started Permit User Sessions. Oct 19 14:34:48 volumio systemd[1]: Started /etc/rc.local Compatibility. Oct 19 14:34:48 volumio systemd[1]: Starting Hold until boot process finishes up... Oct 19 14:34:48 volumio systemd[1]: Starting Terminate Plymouth Boot Screen... Oct 19 14:34:48 volumio systemd[1]: Received SIGRTMIN+21 from PID 329 (plymouthd). Oct 19 14:34:48 volumio systemd[1]: plymouth-quit.service: Succeeded. Oct 19 14:34:48 volumio systemd[1]: Started Terminate Plymouth Boot Screen. Oct 19 14:34:48 volumio systemd[1]: plymouth-quit-wait.service: Succeeded. Oct 19 14:34:48 volumio systemd[1]: Started Hold until boot process finishes up. Oct 19 14:34:48 volumio systemd[1]: Received SIGRTMIN+21 from PID 329 (n/a). Oct 19 14:34:48 volumio systemd[1]: Started Getty on tty1. Oct 19 14:34:48 volumio systemd[1]: Started Serial Getty on ttyS0. Oct 19 14:34:48 volumio systemd[1]: Reached target Login Prompts. Oct 19 14:34:48 volumio ifplugd(eth0)[969]: ifplugd 0.28 initializing. Oct 19 14:34:48 volumio ifplugd(eth0)[969]: Using interface eth0/02:81:05:01:DD:24 with driver (version: Jan_2016) Oct 19 14:34:48 volumio ifplugd(eth0)[969]: Using detection mode: SIOCETHTOOL Oct 19 14:34:48 volumio ifplugd(eth0)[969]: Initialization complete, link beat not detected. Oct 19 14:34:48 volumio loadcpufreq[879]: Loading cpufreq kernel modules...done (none). Oct 19 14:34:48 volumio systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Oct 19 14:34:48 volumio systemd[1]: Starting LSB: set CPUFreq kernel parameters... Oct 19 14:34:48 volumio ifplugd[924]: Network Interface Plugging Daemon...start eth0...done. Oct 19 14:34:48 volumio volumio-remote-updater[786]: Error: No active session Oct 19 14:34:48 volumio systemd[1]: Started LSB: Brings up/down network automatically. Oct 19 14:34:48 volumio volumio-remote-updater[786]: [2024-10-19 14:34:48] [info] asio async_connect error: system:111 (Connection refused) Oct 19 14:34:48 volumio volumio-remote-updater[786]: [2024-10-19 14:34:48] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 19 14:34:48 volumio volumio-remote-updater[786]: [2024-10-19 14:34:48] [error] handle_connect error: Underlying Transport Error Oct 19 14:34:48 volumio cpufrequtils[970]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Oct 19 14:34:48 volumio systemd[1]: Started LSB: set CPUFreq kernel parameters. Oct 19 14:34:48 volumio kernel: random: crng init done Oct 19 14:34:48 volumio kernel: random: 244 urandom warning(s) missed due to ratelimiting Oct 19 14:34:49 volumio ntpd[919]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 19 14:34:49 volumio ntpd[919]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 19 14:34:49 volumio systemd[1]: Started Network Time Service. Oct 19 14:34:49 volumio systemd[1]: systemd-rfkill.service: Succeeded. Oct 19 14:34:49 volumio ntpd[989]: proto: precision = 1.000 usec (-20) Oct 19 14:34:49 volumio ntpd[989]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 19 14:34:49 volumio ntpd[989]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 19 14:34:49 volumio ntpd[989]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 662 days ago Oct 19 14:34:49 volumio ntpd[989]: Listen and drop on 0 v6wildcard [::]:123 Oct 19 14:34:49 volumio ntpd[989]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 19 14:34:49 volumio ntpd[989]: Listen normally on 2 lo 127.0.0.1:123 Oct 19 14:34:49 volumio ntpd[989]: Listening on routing socket on fd #19 for interface updates Oct 19 14:34:49 volumio ntpd[989]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 19 14:34:49 volumio ntpd[989]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 19 14:34:50 volumio ntpd[989]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Oct 19 14:34:50 volumio volumio[782]: Could not open config: /tmp/upmpdcli.conf Oct 19 14:34:51 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Oct 19 14:34:51 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Oct 19 14:34:51 volumio ntpd[989]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Oct 19 14:34:52 volumio nmbd[930]: [2024/10/19 14:34:52.033441, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Oct 19 14:34:52 volumio nmbd[930]: started asyncdns process 991 Oct 19 14:34:52 volumio nmbd[930]: [2024/10/19 14:34:52.037635, 0] ../lib/util/become_daemon.c:149(daemon_status) Oct 19 14:34:52 volumio nmbd[930]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Oct 19 14:34:52 volumio nmbd[930]: [2024/10/19 14:34:52.037968, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Oct 19 14:34:52 volumio nmbd[930]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Oct 19 14:34:52 volumio ntpd[989]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Oct 19 14:34:53 volumio volumio-remote-updater[786]: [2024-10-19 14:34:53] [info] asio async_connect error: system:111 (Connection refused) Oct 19 14:34:53 volumio volumio-remote-updater[786]: [2024-10-19 14:34:53] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 19 14:34:53 volumio volumio-remote-updater[786]: [2024-10-19 14:34:53] [error] handle_connect error: Underlying Transport Error Oct 19 14:34:53 volumio ntpd[989]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Oct 19 14:34:54 volumio wireless.js[768]: Cleaning previous... Oct 19 14:34:54 volumio sudo[1005]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 19 14:34:54 volumio sudo[1005]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:54 volumio sudo[1005]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:54 volumio sudo[1007]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 19 14:34:54 volumio sudo[1007]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:54 volumio sudo[1007]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:55 volumio wireless.js[768]: Stopped aP Oct 19 14:34:55 volumio sudo[1014]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 19 14:34:55 volumio sudo[1014]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:55 volumio kernel: rtl8192cu: MAC auto ON okay! Oct 19 14:34:55 volumio kernel: rtl8192cu: Tx queue select: 0x05 Oct 19 14:34:55 volumio sudo[1014]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:55 volumio sudo[1016]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Oct 19 14:34:55 volumio sudo[1016]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:55 volumio sudo[1016]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:55 volumio sudo[1023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 19 14:34:55 volumio sudo[1023]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:55 volumio sudo[1023]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:55 volumio sudo[1025]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Oct 19 14:34:55 volumio sudo[1025]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:56 volumio sudo[1025]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:56 volumio wireless.js[768]: SETTING APPROPRIATE REG DOMAIN: DE Oct 19 14:34:56 volumio sudo[1030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 19 14:34:56 volumio sudo[1030]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:57 volumio sudo[1030]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:57 volumio sudo[1032]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Oct 19 14:34:57 volumio sudo[1032]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:57 volumio sudo[1032]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:57 volumio wireless.js[768]: SUCCESSFULLY SET NEW REGDOMAIN: DE Oct 19 14:34:57 volumio wireless.js[768]: Start wireless flow Oct 19 14:34:57 volumio wireless.js[768]: Stopped hotspot (if there).. Oct 19 14:34:57 volumio sudo[1037]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 19 14:34:57 volumio sudo[1037]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:57 volumio sudo[1037]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:57 volumio sudo[1039]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 19 14:34:57 volumio sudo[1039]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:57 volumio sudo[1039]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:57 volumio wireless.js[768]: DHCP IP Oct 19 14:34:57 volumio wireless.js[768]: Start ap Oct 19 14:34:57 volumio wpa_supplicant[1041]: Successfully initialized wpa_supplicant Oct 19 14:34:57 volumio sudo[1042]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Oct 19 14:34:57 volumio kernel: rtl8192cu: MAC auto ON okay! Oct 19 14:34:57 volumio sudo[1042]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:57 volumio dhcpcd[1043]: sending commands to master dhcpcd process Oct 19 14:34:57 volumio dhcpcd[854]: control command: /sbin/dhcpcd Oct 19 14:34:57 volumio sudo[1042]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:57 volumio kernel: rtl8192cu: Tx queue select: 0x05 Oct 19 14:34:58 volumio wireless.js[768]: trying... Oct 19 14:34:58 volumio sudo[1046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 19 14:34:58 volumio sudo[1046]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:58 volumio sudo[1046]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:59 volumio wpa_supplicant[1044]: wlan0: SME: Trying to authenticate with 98:9b:cb:f0:4e:ac (SSID='FritzBox7590' freq=2412 MHz) Oct 19 14:34:59 volumio kernel: wlan0: authenticate with 98:9b:cb:f0:4e:ac Oct 19 14:34:59 volumio kernel: wlan0: send auth to 98:9b:cb:f0:4e:ac (try 1/3) Oct 19 14:34:59 volumio wpa_supplicant[1044]: wlan0: Trying to associate with 98:9b:cb:f0:4e:ac (SSID='FritzBox7590' freq=2412 MHz) Oct 19 14:34:59 volumio kernel: wlan0: authenticated Oct 19 14:34:59 volumio kernel: wlan0: associate with 98:9b:cb:f0:4e:ac (try 1/3) Oct 19 14:34:59 volumio kernel: wlan0: RX AssocResp from 98:9b:cb:f0:4e:ac (capab=0x1431 status=0 aid=2) Oct 19 14:34:59 volumio wpa_supplicant[1044]: wlan0: Associated with 98:9b:cb:f0:4e:ac Oct 19 14:34:59 volumio kernel: wlan0: associated Oct 19 14:34:59 volumio wpa_supplicant[1044]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Oct 19 14:34:59 volumio kernel: wlan0: Limiting TX power to 20 (20 - 0) dBm as advertised by 98:9b:cb:f0:4e:ac Oct 19 14:34:59 volumio wireless.js[768]: trying... Oct 19 14:34:59 volumio sudo[1057]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 19 14:34:59 volumio sudo[1057]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:34:59 volumio sudo[1057]: pam_unix(sudo:session): session closed for user root Oct 19 14:34:59 volumio wpa_supplicant[1044]: wlan0: WPA: Key negotiation completed with 98:9b:cb:f0:4e:ac [PTK=CCMP GTK=CCMP] Oct 19 14:34:59 volumio wpa_supplicant[1044]: wlan0: CTRL-EVENT-CONNECTED - Connection to 98:9b:cb:f0:4e:ac completed [id=0 id_str=] Oct 19 14:34:59 volumio dhcpcd[854]: wlan0: carrier acquired Oct 19 14:34:59 volumio wpa_supplicant[1044]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Oct 19 14:34:59 volumio dhcpcd[854]: wlan0: IAID 38:28:a0:cd Oct 19 14:34:59 volumio dhcpcd[854]: wlan0: rebinding lease of 192.168.178.46 Oct 19 14:34:59 volumio dhcpcd[854]: wlan0: probing address 192.168.178.46/24 Oct 19 14:35:00 volumio dhcpcd[854]: wlan0: soliciting an IPv6 router Oct 19 14:35:00 volumio wireless.js[768]: trying... Oct 19 14:35:00 volumio sudo[1075]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 19 14:35:00 volumio sudo[1075]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:00 volumio sudo[1075]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:01 volumio volumio-remote-updater[786]: [2024-10-19 14:35:01] [info] asio async_connect error: system:111 (Connection refused) Oct 19 14:35:01 volumio volumio-remote-updater[786]: [2024-10-19 14:35:01] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 19 14:35:01 volumio volumio-remote-updater[786]: [2024-10-19 14:35:01] [error] handle_connect error: Underlying Transport Error Oct 19 14:35:01 volumio wireless.js[768]: trying... Oct 19 14:35:01 volumio sudo[1078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 19 14:35:01 volumio sudo[1078]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:01 volumio sudo[1078]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:02 volumio wireless.js[768]: trying... Oct 19 14:35:02 volumio sudo[1081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 19 14:35:02 volumio sudo[1081]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:02 volumio sudo[1081]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:03 volumio wireless.js[768]: trying... Oct 19 14:35:03 volumio sudo[1084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 19 14:35:03 volumio sudo[1084]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:03 volumio sudo[1084]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:04 volumio wireless.js[768]: trying... Oct 19 14:35:04 volumio sudo[1087]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 19 14:35:04 volumio sudo[1087]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:04 volumio sudo[1087]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:05 volumio dhcpcd[854]: wlan0: leased 192.168.178.46 for 864000 seconds Oct 19 14:35:05 volumio avahi-daemon[791]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.178.46. Oct 19 14:35:05 volumio avahi-daemon[791]: New relevant interface wlan0.IPv4 for mDNS. Oct 19 14:35:05 volumio dhcpcd[854]: wlan0: adding route to 192.168.178.0/24 Oct 19 14:35:05 volumio avahi-daemon[791]: Registering new address record for 192.168.178.46 on wlan0.IPv4. Oct 19 14:35:05 volumio dhcpcd[854]: wlan0: adding default route via 192.168.178.1 Oct 19 14:35:05 volumio wireless.js[768]: trying... Oct 19 14:35:05 volumio sudo[1110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 19 14:35:05 volumio sudo[1110]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:05 volumio sudo[1110]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:05 volumio wireless.js[768]: Connected to: ----FritzBox7590 Oct 19 14:35:05 volumio wireless.js[768]: ---- Oct 19 14:35:05 volumio sudo[1115]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 19 14:35:05 volumio sudo[1115]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:05 volumio sudo[1115]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:05 volumio wireless.js[768]: ... joined AP, wlan0 IPv4 is 192.168.178.46, ipV6 is undefined Oct 19 14:35:05 volumio wireless.js[768]: It's done! AP Oct 19 14:35:05 volumio iwconfig[1127]: Error for wireless request "Set Power Management" (8B2C) : Oct 19 14:35:05 volumio iwconfig[1127]: SET failed on device wlan0 ; Operation not supported. Oct 19 14:35:05 volumio systemd[1]: Started Wireless Services. Oct 19 14:35:05 volumio systemd[1]: Started Volumio Backend Module. Oct 19 14:35:05 volumio systemd[1]: Started Volumio Cpu Tweaker. Oct 19 14:35:05 volumio ntpd[989]: ntpd exiting on signal 15 (Terminated) Oct 19 14:35:05 volumio systemd[1]: Stopping Network Time Service... Oct 19 14:35:05 volumio systemd[1]: ntp.service: Succeeded. Oct 19 14:35:05 volumio volumio-cpu-tweak[1129]: Setting RT Priority for mpd Oct 19 14:35:05 volumio systemd[1]: Stopped Network Time Service. Oct 19 14:35:05 volumio systemd[1]: Starting Network Time Service... Oct 19 14:35:05 volumio volumio-cpu-tweak[1129]: pid 35's current scheduling policy: SCHED_OTHER Oct 19 14:35:05 volumio volumio-cpu-tweak[1129]: pid 35's current scheduling priority: 0 Oct 19 14:35:05 volumio volumio-cpu-tweak[1129]: Setting MPD Affinity Oct 19 14:35:05 volumio volumio-cpu-tweak[1129]: pid 3's current affinity mask: f Oct 19 14:35:05 volumio volumio-cpu-tweak[1129]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Oct 19 14:35:05 volumio volumio-cpu-tweak[1129]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Oct 19 14:35:05 volumio ntpd[1145]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 19 14:35:05 volumio ntpd[1145]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 19 14:35:05 volumio systemd[1]: Started Network Time Service. Oct 19 14:35:05 volumio ntpd[1154]: proto: precision = 1.000 usec (-20) Oct 19 14:35:05 volumio ntpd[1154]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 19 14:35:05 volumio ntpd[1154]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 19 14:35:05 volumio ntpd[1154]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 662 days ago Oct 19 14:35:05 volumio ntpd[1154]: Listen and drop on 0 v6wildcard [::]:123 Oct 19 14:35:05 volumio ntpd[1154]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 19 14:35:05 volumio ntpd[1154]: Listen normally on 2 lo 127.0.0.1:123 Oct 19 14:35:05 volumio ntpd[1154]: Listen normally on 3 wlan0 192.168.178.46:123 Oct 19 14:35:05 volumio ntpd[1154]: Listening on routing socket on fd #20 for interface updates Oct 19 14:35:05 volumio ntpd[1154]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 19 14:35:05 volumio ntpd[1154]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 19 14:35:05 volumio systemd[1]: volumio_cpu_tweak.service: Succeeded. Oct 19 14:35:06 volumio kernel: vcc3v0: disabling Oct 19 14:35:06 volumio kernel: vcc5v0: disabling Oct 19 14:35:06 volumio ntpd[1154]: Soliciting pool server 131.188.3.220 Oct 19 14:35:07 volumio nmbd[930]: [2024/10/19 14:35:07.049820, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 19 14:35:07 volumio nmbd[930]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Oct 19 14:35:07 volumio systemd[1]: Started Samba NMB Daemon. Oct 19 14:35:07 volumio systemd[1]: Starting Samba Winbind Daemon... Oct 19 14:35:07 volumio winbindd[1157]: [2024/10/19 14:35:07.656405, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Oct 19 14:35:07 volumio winbindd[1157]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Oct 19 14:35:07 volumio winbindd[1157]: [2024/10/19 14:35:07.693931, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 19 14:35:07 volumio winbindd[1157]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Oct 19 14:35:07 volumio systemd[1]: Started Samba Winbind Daemon. Oct 19 14:35:07 volumio systemd[1]: Starting Samba SMB Daemon... Oct 19 14:35:07 volumio ntpd[1154]: Soliciting pool server 185.252.140.125 Oct 19 14:35:07 volumio ntpd[1154]: Soliciting pool server 185.11.138.90 Oct 19 14:35:08 volumio ntpd[1154]: Soliciting pool server 188.245.32.133 Oct 19 14:35:08 volumio ntpd[1154]: Soliciting pool server 141.98.136.83 Oct 19 14:35:08 volumio ntpd[1154]: Soliciting pool server 194.164.164.175 Oct 19 14:35:08 volumio smbd[1165]: [2024/10/19 14:35:08.906186, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 19 14:35:08 volumio systemd[1]: Started Samba SMB Daemon. Oct 19 14:35:08 volumio smbd[1165]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Oct 19 14:35:08 volumio systemd[1]: Reached target Multi-User System. Oct 19 14:35:08 volumio systemd[1]: Reached target Graphical Interface. Oct 19 14:35:08 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Oct 19 14:35:09 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Oct 19 14:35:09 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Oct 19 14:35:09 volumio systemd[1]: Startup finished in 7.575s (kernel) + 29.084s (userspace) = 36.659s. Oct 19 14:35:09 volumio ntpd[1154]: Soliciting pool server 144.76.138.23 Oct 19 14:35:09 volumio ntpd[1154]: Soliciting pool server 157.90.24.29 Oct 19 14:35:09 volumio ntpd[1154]: Soliciting pool server 80.153.195.191 Oct 19 14:35:09 volumio ntpd[1154]: Soliciting pool server 148.251.235.164 Oct 19 14:35:10 volumio ntpd[1154]: Soliciting pool server 129.250.35.250 Oct 19 14:35:10 volumio ntpd[1154]: Soliciting pool server 185.232.69.65 Oct 19 14:35:10 volumio ntpd[1154]: Soliciting pool server 78.46.162.102 Oct 19 14:35:10 volumio volumio[1128]: info: ------------------------------------------- Oct 19 14:35:11 volumio volumio[1128]: info: ----- Volumio3 ---- Oct 19 14:35:11 volumio volumio[1128]: info: ------------------------------------------- Oct 19 14:35:11 volumio volumio[1128]: info: ----- System startup ---- Oct 19 14:35:11 volumio volumio[1128]: info: ------------------------------------------- Oct 19 14:35:11 volumio volumio-remote-updater[786]: [2024-10-19 14:35:11] [connect] Successful connection Oct 19 14:35:11 volumio ntpd[1154]: Soliciting pool server 144.76.43.40 Oct 19 14:35:11 volumio ntpd[1154]: Soliciting pool server 79.133.44.141 Oct 19 14:35:12 volumio ntpd[1154]: Soliciting pool server 5.9.193.27 Oct 19 14:35:12 volumio ntpd[1154]: Soliciting pool server 2003:a:87f:c37c::4 Oct 19 14:35:13 volumio volumio[1128]: info: MYVOLUMIO Environment detected Oct 19 14:35:13 volumio volumio[1128]: info: Plugin folders cleanup Oct 19 14:35:13 volumio volumio[1128]: info: Scanning into folder /volumio/app/plugins/ Oct 19 14:35:13 volumio volumio[1128]: info: Scanning category audio_interface Oct 19 14:35:13 volumio volumio[1128]: info: Scanning category miscellanea Oct 19 14:35:13 volumio volumio[1128]: info: Scanning category music_service Oct 19 14:35:13 volumio volumio[1128]: info: Scanning category plugins.json Oct 19 14:35:13 volumio volumio[1128]: info: Scanning category system_controller Oct 19 14:35:13 volumio volumio[1128]: info: Scanning category user_interface Oct 19 14:35:13 volumio volumio[1128]: info: Scanning into folder /data/plugins/ Oct 19 14:35:13 volumio volumio[1128]: info: Scanning category music_service Oct 19 14:35:13 volumio volumio[1128]: info: Scanning category system_hardware Oct 19 14:35:13 volumio volumio[1128]: info: Plugin folders cleanup completed Oct 19 14:35:13 volumio volumio[1128]: info: ------------------------------------------- Oct 19 14:35:13 volumio volumio[1128]: info: ----- Core plugins startup ---- Oct 19 14:35:13 volumio volumio[1128]: info: ------------------------------------------- Oct 19 14:35:13 volumio volumio[1128]: info: Loading plugins from folder /volumio/app/plugins/ Oct 19 14:35:13 volumio volumio[1128]: info: Adding plugin upnp to MyMusic Plugins Oct 19 14:35:13 volumio volumio[1128]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 19 14:35:13 volumio volumio[1128]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 19 14:35:13 volumio volumio[1128]: info: Loading plugins from folder /data/plugins/ Oct 19 14:35:13 volumio volumio[1128]: info: Loading plugin "system"... Oct 19 14:35:13 volumio volumio[1128]: info: Loading plugin "appearance"... Oct 19 14:35:12 volumio ntpd[1154]: receive: Unexpected origin timestamp 0xeabe2601.bcd70ac6 does not match aorg 0000000000.00000000 from server@144.76.138.23 xmt 0xeabe2600.5de6b126 Oct 19 14:35:13 volumio systemd[1]: systemd-fsckd.service: Succeeded. Oct 19 14:35:14 volumio sh[691]: timed out Oct 19 14:35:14 volumio sh[691]: dhcpcd exited Oct 19 14:35:14 volumio dhcpcd[739]: timed out Oct 19 14:35:14 volumio sh[691]: ifup: failed to bring up eth0 Oct 19 14:35:14 volumio dhcpcd[739]: dhcpcd exited Oct 19 14:35:14 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Oct 19 14:35:14 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Oct 19 14:35:14 volumio volumio[1128]: info: Loading plugin "network"... Oct 19 14:35:14 volumio volumio[1128]: info: Refreshing Cached IP Addresses Oct 19 14:35:14 volumio sudo[1189]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 19 14:35:14 volumio sudo[1189]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:14 volumio sudo[1189]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:14 volumio volumio[1128]: info: Loading plugin "services"... Oct 19 14:35:14 volumio sudo[1191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 19 14:35:14 volumio sudo[1191]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:14 volumio volumio[1128]: info: Loading plugin "alsa_controller"... Oct 19 14:35:14 volumio sudo[1191]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:14 volumio sudo[1194]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 19 14:35:14 volumio sudo[1194]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:14 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 19 14:35:14 volumio volumio[1128]: info: Loading plugin "wizard"... Oct 19 14:35:14 volumio volumio[1128]: info: Loading plugin "networkfs"... Oct 19 14:35:15 volumio volumio[1128]: info: Starting Udev Watcher for removable devices Oct 19 14:35:15 volumio sudo[1200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto 192.168.178.22:/Musik /mnt/NAS/Nas Oct 19 14:35:15 volumio sudo[1200]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:15 volumio volumio[1128]: info: Ignoring mount for partition: boot Oct 19 14:35:15 volumio volumio[1128]: info: Ignoring mount for partition: volumio Oct 19 14:35:15 volumio volumio[1128]: info: Ignoring mount for partition: volumio_data Oct 19 14:35:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 19 14:35:15 volumio volumio[1128]: info: Loading plugin "volumio_command_line_client"... Oct 19 14:35:15 volumio volumio[1128]: info: Loading plugin "upnp"... Oct 19 14:35:15 volumio volumio[1128]: info: [1729341315210] Starting Upmpd Daemon Oct 19 14:35:15 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 19 14:35:15 volumio volumio[1128]: info: Loading plugin "my_music"... Oct 19 14:35:15 volumio volumio[1128]: info: Loading plugin "mpd"... Oct 19 14:35:15 volumio kernel: FS-Cache: Loaded Oct 19 14:35:15 volumio kernel: FS-Cache: Netfs 'nfs' registered for caching Oct 19 14:35:16 volumio volumio[1128]: info: Loading plugin "upnp_browser"... Oct 19 14:35:16 volumio kernel: NFS: Registering the id_resolver key type Oct 19 14:35:16 volumio kernel: Key type id_resolver registered Oct 19 14:35:16 volumio kernel: Key type id_legacy registered Oct 19 14:35:17 volumio sudo[1200]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:17 volumio volumio[1128]: info: Loading plugin "alarm-clock"... Oct 19 14:35:17 volumio volumio[1128]: info: Loading plugin "airplay_emulation"... Oct 19 14:35:17 volumio volumio[1128]: info: Starting Shairport Sync Oct 19 14:35:17 volumio volumio[1128]: info: Loading plugin "last_100"... Oct 19 14:35:17 volumio volumio[1128]: info: Loading plugin "webradio"... Oct 19 14:35:17 volumio volumio[1128]: info: Loading plugin "i2s_dacs"... Oct 19 14:35:17 volumio volumio[1128]: info: I2S DAC not set, start Auto-detection Oct 19 14:35:17 volumio volumio[1128]: info: Loading plugin "volumiodiscovery"... Oct 19 14:35:18 volumio volumio[1128]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 19 14:35:18 volumio volumio[1128]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 19 14:35:18 volumio node[1128]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 19 14:35:18 volumio volumio[1128]: *** WARNING *** For more information see Oct 19 14:35:18 volumio volumio[1128]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 19 14:35:18 volumio volumio[1128]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 19 14:35:18 volumio volumio[1128]: *** WARNING *** For more information see Oct 19 14:35:18 volumio node[1128]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 19 14:35:18 volumio node[1128]: *** WARNING *** For more information see Oct 19 14:35:18 volumio node[1128]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 19 14:35:18 volumio node[1128]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 19 14:35:18 volumio node[1128]: *** WARNING *** For more information see Oct 19 14:35:18 volumio volumio[1128]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 19 14:35:18 volumio volumio[1128]: info: Discovery: Started advertising with name: Volumio Oct 19 14:35:18 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 19 14:35:18 volumio volumio[1128]: info: Loading plugin "spop"... Oct 19 14:35:18 volumio sudo[1194]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:20 volumio volumio[1128]: info: Loading plugin "outputs"... Oct 19 14:35:20 volumio volumio[1128]: info: Loading plugin "albumart"... Oct 19 14:35:20 volumio volumio[1128]: info: Plugin example_plugin is not enabled Oct 19 14:35:20 volumio volumio[1128]: info: Loading plugin "inputs"... Oct 19 14:35:21 volumio volumio[1128]: info: Loading plugin "updater_comm"... Oct 19 14:35:21 volumio volumio[1128]: info: Plugin mpdemulation is not enabled Oct 19 14:35:21 volumio volumio[1128]: info: Loading plugin "rest_api"... Oct 19 14:35:21 volumio volumio[1128]: info: Loading plugin "websocket"... Oct 19 14:35:21 volumio volumio[1128]: info: Starting Socket.io Server version 2.3.0 Oct 19 14:35:21 volumio volumio[1128]: info: Loading plugin "mpd_oled"... Oct 19 14:35:21 volumio volumio[1128]: Forking 3 albumart workers Oct 19 14:35:22 volumio volumio[1128]: info: Applying required configuration parameters for plugin mpd_oled Oct 19 14:35:22 volumio volumio[1128]: info: [MPD_OLED Plugin] Reading configuration file at: /data/configuration/system_hardware/mpd_oled/config.json Oct 19 14:35:22 volumio volumio[1128]: info: Loading i18n strings for locale de Oct 19 14:35:22 volumio volumio[1128]: Updating browse sources language Oct 19 14:35:22 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::initPlayerControls Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: Express server listening on port 3000 Oct 19 14:35:23 volumio volumio[1128]: [Metrics] WebUI: 15s 121.96ms Oct 19 14:35:23 volumio volumio[1128]: info: CoreStateMachine::resetVolumioState Oct 19 14:35:23 volumio volumio[1128]: info: CoreStateMachine::getcurrentVolume Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::volumioRetrievevolume Oct 19 14:35:23 volumio volumio[1128]: info: CoreStateMachine::pushState Oct 19 14:35:23 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 19 14:35:23 volumio volumio[1128]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Oct 19 14:35:23 volumio volumio[1128]: info: Completed loading Core Plugins Oct 19 14:35:23 volumio volumio[1128]: info: Preparing to generate the ALSA configuration file Oct 19 14:35:23 volumio volumio[1128]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Oct 19 14:35:23 volumio volumio[1128]: info: Reading ALSA contributions from plugins. Oct 19 14:35:23 volumio volumio[1128]: Starting albumart workers Oct 19 14:35:23 volumio volumio[1128]: Starting albumart workers Oct 19 14:35:23 volumio volumio[1128]: Starting albumart workers Oct 19 14:35:23 volumio volumio[1128]: verbose: New Socket.io Connection to 192.168.178.46 from 192.168.178.33 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/130.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Oct 19 14:35:23 volumio volumio[1128]: verbose: New Socket.io Connection to 192.168.178.46 from 192.168.178.33 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/130.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Oct 19 14:35:23 volumio volumio[1128]: info: Reloading queue from file Oct 19 14:35:23 volumio volumio[1128]: verbose: New Socket.io Connection to 192.168.178.46 from 192.168.178.33 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/130.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Oct 19 14:35:23 volumio volumio[1128]: info: CoreStateMachine::setRepeat null single undefined Oct 19 14:35:23 volumio volumio[1128]: info: CoreStateMachine::pushState Oct 19 14:35:23 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Oct 19 14:35:23 volumio volumio[1128]: info: CoreStateMachine::setRandom null Oct 19 14:35:23 volumio volumio[1128]: info: CoreStateMachine::pushState Oct 19 14:35:23 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:23 volumio volumio[1128]: info: CoreCommandRouter::volumioPushState Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::volumioGetVisibleSources Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:24 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 19 14:35:24 volumio volumio[1128]: info: Received Get System Info Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 19 14:35:24 volumio volumio[1128]: info: Discovery: Getting this device information Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:24 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:24 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:24 volumio volumio[1128]: info: Listing playlists Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::volumioGetQueue Oct 19 14:35:24 volumio volumio[1128]: info: CoreStateMachine::getQueue Oct 19 14:35:24 volumio volumio[1128]: info: CorePlayQueue::getQueue Oct 19 14:35:24 volumio volumio[1128]: info: Discovery: adding 4f1f6f1e-31f3-4468-b982-f1c050875f64 Oct 19 14:35:24 volumio volumio[1128]: info: Discovery: Found device Volumio Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:24 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:24 volumio volumio[1128]: info: Asound.conf file unchanged, so no further update is needed Oct 19 14:35:24 volumio volumio[1128]: info: Output device has changed, restarting MPD Oct 19 14:35:24 volumio volumio[1128]: info: Output device has changed, restarting Shairport Sync Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 19 14:35:24 volumio sudo[1254]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 19 14:35:24 volumio sudo[1254]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:24 volumio sudo[1254]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:24 volumio sudo[1255]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 19 14:35:24 volumio sudo[1255]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:24 volumio volumio[1128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 19 14:35:24 volumio volumio[1128]: info: ___________ START PLUGINS ___________ Oct 19 14:35:24 volumio volumio[1128]: info: ControllerMpd::onStart: Initializing MPD Oct 19 14:35:24 volumio volumio[1128]: info: Creating MPD Configuration file Oct 19 14:35:24 volumio systemd[1]: Listening on mpd.socket. Oct 19 14:35:24 volumio volumio-remote-updater[786]: [2024-10-19 14:35:24] [connect] Successful connection Oct 19 14:35:24 volumio systemd[1]: Starting Music Player Daemon... Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 19 14:35:24 volumio volumio[1128]: info: [1729341324865] CoreMusicLibrary::Adding element Medienserver Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 19 14:35:24 volumio sudo[1264]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 19 14:35:24 volumio sudo[1264]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:24 volumio sudo[1264]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:24 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 19 14:35:24 volumio sudo[1266]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 19 14:35:24 volumio sudo[1266]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:25 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 19 14:35:25 volumio systemd[1]: mpd.service: Succeeded. Oct 19 14:35:25 volumio systemd[1]: Stopped Music Player Daemon. Oct 19 14:35:25 volumio systemd[1]: Starting Music Player Daemon... Oct 19 14:35:25 volumio volumio[1128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 19 14:35:25 volumio volumio[1128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 19 14:35:25 volumio volumio[1128]: info: [1729341325191] CoreMusicLibrary::Adding element Last_100 Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 19 14:35:25 volumio volumio[1128]: info: [1729341325215] CoreMusicLibrary::Adding element Webradio Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 19 14:35:25 volumio volumio[1128]: info: Initializing BBC Radios Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 19 14:35:25 volumio sudo[1280]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 19 14:35:25 volumio sudo[1280]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:25 volumio sudo[1280]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 19 14:35:25 volumio sudo[1280]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:25 volumio volumio[1128]: info: Creating Spotify config file Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:25 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Oct 19 14:35:25 volumio volumio[1128]: info: Volumio Calling Home Oct 19 14:35:25 volumio sudo[1315]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /tmp/mpd_oled_plugin.sh Oct 19 14:35:25 volumio sudo[1315]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:25 volumio sudo[1315]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:25 volumio sudo[1317]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start mpd_oled_plugin.service Oct 19 14:35:25 volumio sudo[1317]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:25 volumio volumio[1128]: info: Preparing to generate the ALSA configuration file Oct 19 14:35:26 volumio sudo[1324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 19 14:35:26 volumio sudo[1324]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:26 volumio volumio[1128]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Oct 19 14:35:26 volumio volumio[1128]: info: Reading ALSA contributions from plugins. Oct 19 14:35:26 volumio sudo[1324]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:26 volumio sudo[1326]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 19 14:35:26 volumio sudo[1326]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:26 volumio sudo[1326]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:26 volumio volumio[1128]: info: [MPD_OLED Plugin] Set execute permissions on /tmp/mpd_oled_plugin.sh Oct 19 14:35:26 volumio volumio[1128]: info: MPD Permissions set Oct 19 14:35:26 volumio volumio[1128]: info: MPD Permissions set Oct 19 14:35:26 volumio volumio-remote-updater[786]: [2024-10-19 14:35:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1729341324 101 Oct 19 14:35:26 volumio volumio[1128]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 4 Oct 19 14:35:26 volumio volumio[1128]: info: Volumio called home Oct 19 14:35:26 volumio volumio[1128]: info: Spotify config file written Oct 19 14:35:26 volumio volumio[1128]: info: [MPD_OLED Plugin] tmp script created /tmp/mpd_oled_plugin.sh Oct 19 14:35:26 volumio volumio[1128]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 19 14:35:26 volumio sudo[1330]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio sudo[1330]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 19 14:35:26 volumio systemd[1]: Started go-librespot Daemon. Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio go-librespot[1338]: Librespot-go daemon starting... Oct 19 14:35:26 volumio sudo[1330]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:26 volumio wpa_supplicant[1044]: wlan0: WPA: Group rekeying completed with 98:9b:cb:f0:4e:ac [GTK=CCMP] Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 19 14:35:26 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:27 volumio volumio[1128]: info: Starting Shairport Sync Oct 19 14:35:27 volumio volumio[1128]: info: Starting Shairport Sync Oct 19 14:35:27 volumio sudo[1352]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 19 14:35:27 volumio sudo[1352]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:27 volumio volumio[1128]: info: Starting Shairport Sync Oct 19 14:35:27 volumio sudo[1354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 19 14:35:27 volumio sudo[1354]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:27 volumio sudo[1357]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 19 14:35:27 volumio go-librespot[1338]: time="2024-10-19T14:35:27+02:00" level=info msg="generated new device id: b8d9d1ad9eab28b68e212c5528319a8b25548e06" Oct 19 14:35:27 volumio sudo[1357]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:27 volumio go-librespot[1338]: time="2024-10-19T14:35:27+02:00" level=debug msg="stored credentials found for penkypenk" Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:27 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:27 volumio sudo[1360]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 19 14:35:27 volumio sudo[1360]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:27 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 19 14:35:27 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Oct 19 14:35:27 volumio sudo[1352]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:27 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 19 14:35:27 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 19 14:35:27 volumio volumio[1128]: info: Asound.conf file unchanged, so no further update is needed Oct 19 14:35:27 volumio volumio[1128]: info: Output device has changed, restarting MPD Oct 19 14:35:27 volumio volumio[1128]: info: Output device has changed, restarting Shairport Sync Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 19 14:35:27 volumio sudo[1365]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 19 14:35:27 volumio sudo[1365]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:27 volumio sudo[1365]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:27 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 19 14:35:27 volumio sudo[1354]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:27 volumio sudo[1357]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:27 volumio sudo[1368]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 19 14:35:27 volumio sudo[1368]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:27 volumio volumio[1128]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 19 14:35:27 volumio volumio[1128]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 19 14:35:27 volumio volumio[1128]: SPOTIFY: BQCWsiFsUbn-rUl9lnrbuvZWTtW20SFzlUYdEBP70iXmV1dnabAGcUU0ELdsD9o9tZ7MMUL8whKAzGW3wwoCmpz8cRFyzVlUlRcHsjYWkQ1ls2lN4o6iQwKBT7EnnzRPtNyvj630uY2cFYZW3OMLbp55lrl8NbbJI4yO8MlIGlidhgajwbViICi42Iq_bKW1d07o61F--KzH1fC6r7KdrxGE7H-jNV62kQYZdxQJJ5wcUQ23SO5Z9Cy-nA Oct 19 14:35:27 volumio volumio[1128]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 19 14:35:27 volumio volumio[1128]: info: New Spotify access token = BQCWsiFsUbn-rUl9lnrbuvZWTtW20SFzlUYdEBP70iXmV1dnabAGcUU0ELdsD9o9tZ7MMUL8whKAzGW3wwoCmpz8cRFyzVlUlRcHsjYWkQ1ls2lN4o6iQwKBT7EnnzRPtNyvj630uY2cFYZW3OMLbp55lrl8NbbJI4yO8MlIGlidhgajwbViICi42Iq_bKW1d07o61F--KzH1fC6r7KdrxGE7H-jNV62kQYZdxQJJ5wcUQ23SO5Z9Cy-nA Oct 19 14:35:27 volumio volumio[1128]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 19 14:35:27 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 19 14:35:27 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 19 14:35:27 volumio systemd[1]: mpd.service: Succeeded. Oct 19 14:35:27 volumio systemd[1]: Stopped Music Player Daemon. Oct 19 14:35:27 volumio volumio[1128]: info: Upmpdcli Daemon Started Oct 19 14:35:27 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 19 14:35:27 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 19 14:35:27 volumio volumio[1128]: info: MPD Permissions set Oct 19 14:35:27 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 19 14:35:27 volumio volumio[1128]: info: Shairport-Sync Started Oct 19 14:35:27 volumio volumio[1128]: Error adding Membership: Error: addMembership EINVAL Oct 19 14:35:27 volumio volumio[1128]: info: Shairport-Sync Started Oct 19 14:35:27 volumio sudo[1360]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:27 volumio volumio[1128]: info: Shairport-Sync Started Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:27 volumio systemd[1]: Starting Music Player Daemon... Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:27 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 19 14:35:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 19 14:35:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 19 14:35:28 volumio volumio[1128]: info: Starting Shairport Sync Oct 19 14:35:28 volumio sudo[1389]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 19 14:35:28 volumio sudo[1389]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:28 volumio sudo[1377]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 19 14:35:28 volumio sudo[1377]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 19 14:35:28 volumio sudo[1377]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 19 14:35:28 volumio sudo[1377]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:28 volumio volumio[1128]: SPOTIFY: User informations: {"country":"DE","display_name":"penkypenk","email":"patrick.t.mueller@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/penkypenk"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/penkypenk","id":"penkypenk","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85a422d1365ab3d67de28d6d30","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82a422d1365ab3d67de28d6d30","width":64}],"product":"premium","type":"user","uri":"spotify:user:penkypenk"} Oct 19 14:35:28 volumio volumio[1128]: info: Spotify Successfully logged in Oct 19 14:35:28 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 19 14:35:28 volumio volumio[1128]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 19 14:35:28 volumio volumio[1128]: info: [1729341328250] CoreMusicLibrary::Adding element Spotify Oct 19 14:35:28 volumio volumio[1128]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 19 14:35:28 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 19 14:35:28 volumio volumio[1128]: Cannot find translation for source Spotify Oct 19 14:35:28 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 19 14:35:28 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 19 14:35:28 volumio go-librespot[1338]: time="2024-10-19T14:35:28+02:00" level=debug msg="obtained new client token: AACJosur0xwx9inSeo+QFUcSf3YijDm8JcrWBEBDyjhsjQLMlXj+SKKsQR+SuavAGgZmBMSp7NHLUT1pdxMWkyE3LL3fDomkqynUep/MjHNJFnL5iHkAbqWa2UdQ3Ef3aWUzEHvLfQHLoRR7CM4bUDE+SXnh4a/glj0cDmTZCIKmPyk+Q3ZPk/2BPdG63eyiFjUfTwF0SeMcIAYlwN5M57VWwgkkBMQ+7DzS4NQvMsfPfxWToImQmUB7VN+o" Oct 19 14:35:28 volumio sudo[1389]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:28 volumio volumio[1128]: info: Shairport-Sync Started Oct 19 14:35:28 volumio go-librespot[1338]: time="2024-10-19T14:35:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 19 14:35:28 volumio go-librespot[1338]: time="2024-10-19T14:35:28+02:00" level=debug msg="completed keyexchange" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="completed challenge" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="authenticated as penkypenk" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="authenticated as penkypenk" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="dealer connection opened" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="received connection id: NDQyMmE5NzAtMDc5OC00ZDIzLTliMzQtODIxYmM2ZGEwNzhjK2RlYWxlcit0Y3A6Ly8wYWNhNTkxOS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArRUQxRTA3RjE1RTg3RkJGRkYzNDA1M0M5NUQ2N0ZENjE2RjM5RDA1Q0EyNDZBMjRDQkQ0REZBNjg3QzFGQjVCNA==" Oct 19 14:35:29 volumio go-librespot[1338]: time="2024-10-19T14:35:29+02:00" level=debug msg="put connect state because NEW_DEVICE" Oct 19 14:35:30 volumio volumio[1128]: info: go-librespot daemon successfully initialized Oct 19 14:35:31 volumio mpd[1392]: Oct 19 14:35 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 19 14:35:31 volumio systemd[1]: Started Music Player Daemon. Oct 19 14:35:31 volumio volumio[1128]: Upnp client error: Error: This socket has been ended by the other party Oct 19 14:35:31 volumio sudo[1368]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:31 volumio sudo[1266]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:31 volumio sudo[1255]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:31 volumio systemd[1]: Started MPD OLED Plugin. Oct 19 14:35:31 volumio sudo[1317]: pam_unix(sudo:session): session closed for user root Oct 19 14:35:31 volumio volumio[1128]: info: Completed starting Core Plugins Oct 19 14:35:31 volumio volumio[1128]: info: ------------------------------------------- Oct 19 14:35:31 volumio volumio[1128]: info: ----- MyVolumio plugins startup ---- Oct 19 14:35:31 volumio volumio[1128]: info: ------------------------------------------- Oct 19 14:35:31 volumio volumio[1128]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 19 14:35:31 volumio volumio[1128]: info: MPD running with PID1392 Oct 19 14:35:31 volumio volumio[1128]: ,establishing connection Oct 19 14:35:31 volumio volumio[1128]: info: [MPD_OLED Plugin] Started mpd_oled_plugin service Oct 19 14:35:31 volumio volumio[1128]: error: MPD error: The expression evaluated to a falsy value: Oct 19 14:35:31 volumio volumio[1128]: assert.ok(self.idling) Oct 19 14:35:31 volumio volumio[1128]: error: The expression evaluated to a falsy value: Oct 19 14:35:31 volumio volumio[1128]: assert.ok(self.idling) Oct 19 14:35:31 volumio volumio[1128]: error: MPD error: The expression evaluated to a falsy value: Oct 19 14:35:31 volumio volumio[1128]: assert.ok(self.idling) Oct 19 14:35:31 volumio volumio[1128]: error: The expression evaluated to a falsy value: Oct 19 14:35:31 volumio volumio[1128]: assert.ok(self.idling) Oct 19 14:35:31 volumio volumio[1128]: error: MPD error: The expression evaluated to a falsy value: Oct 19 14:35:31 volumio volumio[1128]: assert.ok(self.idling) Oct 19 14:35:31 volumio volumio[1128]: error: The expression evaluated to a falsy value: Oct 19 14:35:31 volumio volumio[1128]: assert.ok(self.idling) Oct 19 14:35:31 volumio volumio[1128]: error: updateQueue error: null Oct 19 14:35:31 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:31 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:31 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:31 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:31 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:31 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:31 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:31 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:31 volumio volumio[1363]: Generating RSA private key, 4096 bit long modulus (2 primes) Oct 19 14:35:32 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:32 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:32 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:32 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:32 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:32 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:32 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:32 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:32 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:32 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:32 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:32 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:32 volumio go-librespot[1338]: time="2024-10-19T14:35:32+02:00" level=debug msg="handling transfer player command from c896a175a30f26302d2ce5bc9b44b92200527acb" Oct 19 14:35:33 volumio volumio[1128]: info: Initializing connection to go-librespot Websocket Oct 19 14:35:33 volumio go-librespot[1338]: time="2024-10-19T14:35:33+02:00" level=debug msg="new websocket client" Oct 19 14:35:33 volumio volumio[1128]: info: Connection to go-librespot Websocket established Oct 19 14:35:33 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:33 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:33 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:33 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:33 volumio go-librespot[1338]: time="2024-10-19T14:35:33+02:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Oct 19 14:35:33 volumio go-librespot[1338]: time="2024-10-19T14:35:33+02:00" level=debug msg="loading track spotify:track:4QhOVVPK4mXXMMUVgqCycD (paused: true, position: 95443ms)" Oct 19 14:35:33 volumio go-librespot[1338]: time="2024-10-19T14:35:33+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 19 14:35:33 volumio go-librespot[1338]: time="2024-10-19T14:35:33+02:00" level=trace msg="emitting websocket event: will_play" Oct 19 14:35:33 volumio volumio[1128]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4QhOVVPK4mXXMMUVgqCycD","play_origin":"android-auto"}} Oct 19 14:35:33 volumio go-librespot[1338]: time="2024-10-19T14:35:33+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Oct 19 14:35:33 volumio go-librespot[1338]: time="2024-10-19T14:35:33+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4QhOVVPK4mXXMMUVgqCycD" Oct 19 14:35:33 volumio go-librespot[1338]: time="2024-10-19T14:35:33+02:00" level=debug msg="requested aes key for file 46fe483012033b18b45006c7dca176c7990c9dc9, gid: 4QhOVVPK4mXXMMUVgqCycD" Oct 19 14:35:33 volumio go-librespot[1338]: time="2024-10-19T14:35:33+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1684" Oct 19 14:35:33 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:33 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:33 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:33 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:33 volumio go-librespot[1338]: time="2024-10-19T14:35:33+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1296" Oct 19 14:35:34 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:34 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:34 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:34 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:34 volumio go-librespot[1338]: time="2024-10-19T14:35:34+02:00" level=debug msg="fetched first chunk of 12, total size is 5847484 bytes" Oct 19 14:35:34 volumio go-librespot[1338]: time="2024-10-19T14:35:34+02:00" level=debug msg="fetched chunk 2/11, size: 524288" Oct 19 14:35:34 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:34 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:34 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:34 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:34 volumio go-librespot[1338]: time="2024-10-19T14:35:34+02:00" level=debug msg="fetched chunk 1/11, size: 524288" Oct 19 14:35:34 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:34 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:35 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:35 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=debug msg="fetched chunk 3/11, size: 524288" Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=debug msg="fetched chunk 9/11, size: 524288" Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=debug msg="fetched chunk 10/11, size: 524288" Oct 19 14:35:35 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:35 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:35 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:35 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=debug msg="fetched chunk 8/11, size: 524288" Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=debug msg="fetched chunk 7/11, size: 524288" Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=trace msg="seek to 95443ms (diff: 83ms, samples: 4209036, bytes: 4018980)" Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=info msg="loaded track \"The Devils Whip\" (uri: spotify:track:4QhOVVPK4mXXMMUVgqCycD, paused: true, position: 95443ms, duration: 140043ms)" Oct 19 14:35:35 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:35 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:35 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:35 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=trace msg="emitting websocket event: metadata" Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=trace msg="emitting websocket event: active" Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=debug msg="sending successful reply for delaer request" Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 19 14:35:35 volumio volumio[1128]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4QhOVVPK4mXXMMUVgqCycD","name":"The Devils Whip","artist_names":["Orange Goblin"],"album_name":"Rough \u0026 Ready, Live \u0026 Loud","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021c388dd564210ce328257fe8","position":95443,"duration":140043,"release_date":"year:2020 month:5 day:15","track_number":2,"disc_number":1}} Oct 19 14:35:35 volumio volumio[1128]: SPOTIFY: received: {"type":"active","data":null} Oct 19 14:35:35 volumio volumio[1128]: info: Aligning Spotify Volume to Volumio Volume Oct 19 14:35:35 volumio volumio[1128]: info: CoreCommandRouter::volumioGetState Oct 19 14:35:35 volumio volumio[1128]: info: CorePlayQueue::getTrack 0 Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 19 14:35:35 volumio go-librespot[1338]: time="2024-10-19T14:35:35+02:00" level=trace msg="emitting websocket event: paused" Oct 19 14:35:35 volumio volumio[1128]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4QhOVVPK4mXXMMUVgqCycD","play_origin":"android-auto"}} Oct 19 14:35:35 volumio volumio[1128]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 19 14:35:36 volumio volumio[1128]: TypeError: Cannot read property 'service' of undefined Oct 19 14:35:36 volumio volumio[1128]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Oct 19 14:35:36 volumio volumio[1128]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:270:18) Oct 19 14:35:36 volumio volumio[1128]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Oct 19 14:35:36 volumio volumio[1128]: at WebSocket.emit (events.js:400:28) Oct 19 14:35:36 volumio volumio[1128]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Oct 19 14:35:36 volumio volumio[1128]: at Receiver.emit (events.js:400:28) Oct 19 14:35:36 volumio volumio[1128]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Oct 19 14:35:36 volumio volumio[1128]: at internal/process/task_queues.js:141:7 Oct 19 14:35:36 volumio volumio[1128]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Oct 19 14:35:36 volumio volumio[1128]: at AsyncResource.runMicrotask (internal/process/task_queues.js:138:8) Oct 19 14:35:36 volumio volumio[1128]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 19 14:35:36 volumio volumio[1128]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 19 14:35:37 volumio sudo[1495]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-19 14:34 Oct 19 14:35:37 volumio sudo[1495]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 20 Sep 2024 10:02:06 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="orangepione" VOLUMIO_DEVICENAME="Orange Pi One" VOLUMIO_HASH="196dbf07455fd638bf5080f981aa4211"