-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Thu 2025-06-12 13:55:05 CEST. -- Jun 12 13:54:03 volumiodvs2 kernel: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=826680f7-a407-4ab9-8bd5-1855bda526fd imgfile=/volumio_current.sqsh bootpart=UUID=FD90-ED9E datapart=UUID=fecb0823-2e5b-4bba-9498-dd37b5084148 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Jun 12 13:54:03 volumiodvs2 kernel: Unknown kernel command line parameters "splash nodebug imgpart=UUID=826680f7-a407-4ab9-8bd5-1855bda526fd imgfile=/volumio_current.sqsh bootpart=UUID=FD90-ED9E datapart=UUID=fecb0823-2e5b-4bba-9498-dd37b5084148 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe bootdelay=7 use_kmsg=no", will be passed to user space. Jun 12 13:54:03 volumiodvs2 kernel: Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Jun 12 13:54:03 volumiodvs2 kernel: Memory: 810820K/917504K available (10240K kernel code, 1454K rwdata, 3144K rodata, 1024K init, 612K bss, 41148K reserved, 65536K cma-reserved) Jun 12 13:54:03 volumiodvs2 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Jun 12 13:54:03 volumiodvs2 kernel: ftrace: allocating 34953 entries in 103 pages Jun 12 13:54:03 volumiodvs2 kernel: ftrace: allocated 103 pages with 5 groups Jun 12 13:54:03 volumiodvs2 kernel: trace event string verifier disabled Jun 12 13:54:03 volumiodvs2 kernel: rcu: Hierarchical RCU implementation. Jun 12 13:54:03 volumiodvs2 kernel: Rude variant of Tasks RCU enabled. Jun 12 13:54:03 volumiodvs2 kernel: Tracing variant of Tasks RCU enabled. Jun 12 13:54:03 volumiodvs2 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Jun 12 13:54:03 volumiodvs2 kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Jun 12 13:54:03 volumiodvs2 kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Jun 12 13:54:03 volumiodvs2 kernel: arch_timer: cp15 timer(s) running at 19.20MHz (phys). Jun 12 13:54:03 volumiodvs2 kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns Jun 12 13:54:03 volumiodvs2 kernel: sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns Jun 12 13:54:03 volumiodvs2 kernel: Switching to timer-based delay loop, resolution 52ns Jun 12 13:54:03 volumiodvs2 kernel: Console: colour dummy device 80x30 Jun 12 13:54:03 volumiodvs2 kernel: printk: console [tty1] enabled Jun 12 13:54:03 volumiodvs2 kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000) Jun 12 13:54:03 volumiodvs2 kernel: CPU: Testing write buffer coherency: ok Jun 12 13:54:03 volumiodvs2 kernel: pid_max: default: 32768 minimum: 301 Jun 12 13:54:03 volumiodvs2 kernel: LSM: Security Framework initializing Jun 12 13:54:03 volumiodvs2 kernel: Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: cgroup: Disabling memory control group subsystem Jun 12 13:54:03 volumiodvs2 kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Jun 12 13:54:03 volumiodvs2 kernel: cblist_init_generic: Setting adjustable number of callback queues. Jun 12 13:54:03 volumiodvs2 kernel: cblist_init_generic: Setting shift to 2 and lim to 1. Jun 12 13:54:03 volumiodvs2 kernel: cblist_init_generic: Setting adjustable number of callback queues. Jun 12 13:54:03 volumiodvs2 kernel: cblist_init_generic: Setting shift to 2 and lim to 1. Jun 12 13:54:03 volumiodvs2 kernel: Setting up static identity map for 0x100000 - 0x10003c Jun 12 13:54:03 volumiodvs2 kernel: rcu: Hierarchical SRCU implementation. Jun 12 13:54:03 volumiodvs2 kernel: rcu: Max phase no-delay instances is 1000. Jun 12 13:54:03 volumiodvs2 kernel: smp: Bringing up secondary CPUs ... Jun 12 13:54:03 volumiodvs2 kernel: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Jun 12 13:54:03 volumiodvs2 kernel: CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Jun 12 13:54:03 volumiodvs2 kernel: CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Jun 12 13:54:03 volumiodvs2 kernel: smp: Brought up 1 node, 4 CPUs Jun 12 13:54:03 volumiodvs2 kernel: SMP: Total of 4 processors activated (153.60 BogoMIPS). Jun 12 13:54:03 volumiodvs2 kernel: CPU: All CPU(s) started in HYP mode. Jun 12 13:54:03 volumiodvs2 kernel: CPU: Virtualization extensions available. Jun 12 13:54:03 volumiodvs2 kernel: devtmpfs: initialized Jun 12 13:54:03 volumiodvs2 kernel: VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4 Jun 12 13:54:03 volumiodvs2 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Jun 12 13:54:03 volumiodvs2 kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: pinctrl core: initialized pinctrl subsystem Jun 12 13:54:03 volumiodvs2 kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Jun 12 13:54:03 volumiodvs2 kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Jun 12 13:54:03 volumiodvs2 kernel: audit: initializing netlink subsys (disabled) Jun 12 13:54:03 volumiodvs2 kernel: audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1 Jun 12 13:54:03 volumiodvs2 kernel: thermal_sys: Registered thermal governor 'step_wise' Jun 12 13:54:03 volumiodvs2 kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Jun 12 13:54:03 volumiodvs2 kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Jun 12 13:54:03 volumiodvs2 kernel: Serial: AMBA PL011 UART driver Jun 12 13:54:03 volumiodvs2 kernel: bcm2835-mbox 3f00b880.mailbox: mailbox enabled Jun 12 13:54:03 volumiodvs2 kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2023-10-17T15:42:39, variant start Jun 12 13:54:03 volumiodvs2 kernel: raspberrypi-firmware soc:firmware: Firmware hash is 30f0c5e4d076da3ab4f341d88e7d505760b93ad7 Jun 12 13:54:03 volumiodvs2 kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Jun 12 13:54:03 volumiodvs2 kernel: bcm2835-dma 3f007000.dma: DMA legacy API manager, dmachans=0x1 Jun 12 13:54:03 volumiodvs2 kernel: SCSI subsystem initialized Jun 12 13:54:03 volumiodvs2 kernel: usbcore: registered new interface driver usbfs Jun 12 13:54:03 volumiodvs2 kernel: usbcore: registered new interface driver hub Jun 12 13:54:03 volumiodvs2 kernel: usbcore: registered new device driver usb Jun 12 13:54:03 volumiodvs2 kernel: usb_phy_generic phy: supply vcc not found, using dummy regulator Jun 12 13:54:03 volumiodvs2 kernel: pps_core: LinuxPPS API ver. 1 registered Jun 12 13:54:03 volumiodvs2 kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti Jun 12 13:54:03 volumiodvs2 kernel: PTP clock support registered Jun 12 13:54:03 volumiodvs2 kernel: clocksource: Switched to clocksource arch_sys_counter Jun 12 13:54:03 volumiodvs2 kernel: VFS: Disk quotas dquot_6.6.0 Jun 12 13:54:03 volumiodvs2 kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Jun 12 13:54:03 volumiodvs2 kernel: FS-Cache: Loaded Jun 12 13:54:03 volumiodvs2 kernel: CacheFiles: Loaded Jun 12 13:54:03 volumiodvs2 kernel: NET: Registered PF_INET protocol family Jun 12 13:54:03 volumiodvs2 kernel: IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: TCP bind hash table entries: 8192 (order: 5, 131072 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: TCP: Hash tables configured (established 8192 bind 8192) Jun 12 13:54:03 volumiodvs2 kernel: UDP hash table entries: 512 (order: 2, 16384 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) Jun 12 13:54:03 volumiodvs2 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Jun 12 13:54:03 volumiodvs2 kernel: RPC: Registered named UNIX socket transport module. Jun 12 13:54:03 volumiodvs2 kernel: RPC: Registered udp transport module. Jun 12 13:54:03 volumiodvs2 kernel: RPC: Registered tcp transport module. Jun 12 13:54:03 volumiodvs2 kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Jun 12 13:54:03 volumiodvs2 kernel: Trying to unpack rootfs image as initramfs... Jun 12 13:54:03 volumiodvs2 kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available Jun 12 13:54:03 volumiodvs2 kernel: Freeing initrd memory: 14316K Jun 12 13:54:03 volumiodvs2 kernel: Initialise system trusted keyrings Jun 12 13:54:03 volumiodvs2 kernel: workingset: timestamp_bits=14 max_order=18 bucket_order=4 Jun 12 13:54:03 volumiodvs2 kernel: zbud: loaded Jun 12 13:54:03 volumiodvs2 kernel: NFS: Registering the id_resolver key type Jun 12 13:54:03 volumiodvs2 kernel: Key type id_resolver registered Jun 12 13:54:03 volumiodvs2 kernel: Key type id_legacy registered Jun 12 13:54:03 volumiodvs2 kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Jun 12 13:54:03 volumiodvs2 kernel: nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Jun 12 13:54:03 volumiodvs2 kernel: Key type asymmetric registered Jun 12 13:54:03 volumiodvs2 kernel: Asymmetric key parser 'x509' registered Jun 12 13:54:03 volumiodvs2 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) Jun 12 13:54:03 volumiodvs2 kernel: io scheduler mq-deadline registered Jun 12 13:54:03 volumiodvs2 kernel: io scheduler kyber registered Jun 12 13:54:03 volumiodvs2 kernel: bcm2708_fb soc:fb: FB found 1 display(s) Jun 12 13:54:03 volumiodvs2 kernel: Console: switching to colour frame buffer device 80x30 Jun 12 13:54:03 volumiodvs2 kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Jun 12 13:54:03 volumiodvs2 kernel: bcm2835-rng 3f104000.rng: hwrng registered Jun 12 13:54:03 volumiodvs2 kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Jun 12 13:54:03 volumiodvs2 kernel: brd: module loaded Jun 12 13:54:03 volumiodvs2 kernel: loop: module loaded Jun 12 13:54:03 volumiodvs2 kernel: Loading iSCSI transport class v2.0-870. Jun 12 13:54:03 volumiodvs2 kernel: usbcore: registered new interface driver lan78xx Jun 12 13:54:03 volumiodvs2 kernel: usbcore: registered new interface driver smsc95xx Jun 12 13:54:03 volumiodvs2 kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Jun 12 13:54:03 volumiodvs2 kernel: Core Release: 2.80a Jun 12 13:54:03 volumiodvs2 kernel: Setting default values for core params Jun 12 13:54:03 volumiodvs2 kernel: Finished setting default values for core params Jun 12 13:54:03 volumiodvs2 kernel: Using Buffer DMA mode Jun 12 13:54:03 volumiodvs2 kernel: Periodic Transfer Interrupt Enhancement - disabled Jun 12 13:54:03 volumiodvs2 kernel: Multiprocessor Interrupt Enhancement - disabled Jun 12 13:54:03 volumiodvs2 kernel: OTG VER PARAM: 0, OTG VER FLAG: 0 Jun 12 13:54:03 volumiodvs2 kernel: Dedicated Tx FIFOs mode Jun 12 13:54:03 volumiodvs2 kernel: Jun 12 13:54:03 volumiodvs2 kernel: WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = b4104000 dma = 0xf4104000 len=9024 Jun 12 13:54:03 volumiodvs2 kernel: FIQ FSM acceleration enabled for : Non-periodic Split Transactions Periodic Split Transactions High-Speed Isochronous Endpoints Interrupt/Control Split Transaction hack enabled Jun 12 13:54:03 volumiodvs2 kernel: dwc_otg: Microframe scheduler enabled Jun 12 13:54:03 volumiodvs2 kernel: Jun 12 13:54:03 volumiodvs2 kernel: WARN::hcd_init_fiq:457: FIQ on core 1 Jun 12 13:54:03 volumiodvs2 kernel: Jun 12 13:54:03 volumiodvs2 kernel: WARN::hcd_init_fiq:458: FIQ ASM at 807c7754 length 36 Jun 12 13:54:03 volumiodvs2 kernel: Jun 12 13:54:03 volumiodvs2 kernel: WARN::hcd_init_fiq:497: MPHI regs_base at b8810000 Jun 12 13:54:03 volumiodvs2 kernel: dwc_otg 3f980000.usb: DWC OTG Controller Jun 12 13:54:03 volumiodvs2 kernel: dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1 Jun 12 13:54:03 volumiodvs2 kernel: dwc_otg 3f980000.usb: irq 89, io mem 0x00000000 Jun 12 13:54:03 volumiodvs2 kernel: Init: Port Power? op_state=1 Jun 12 13:54:03 volumiodvs2 kernel: Init: Power Port (0) Jun 12 13:54:03 volumiodvs2 kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.01 Jun 12 13:54:03 volumiodvs2 kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Jun 12 13:54:03 volumiodvs2 kernel: usb usb1: Product: DWC OTG Controller Jun 12 13:54:03 volumiodvs2 kernel: usb usb1: Manufacturer: Linux 6.1.77-v7+ dwc_otg_hcd Jun 12 13:54:03 volumiodvs2 kernel: usb usb1: SerialNumber: 3f980000.usb Jun 12 13:54:03 volumiodvs2 kernel: hub 1-0:1.0: USB hub found Jun 12 13:54:03 volumiodvs2 kernel: hub 1-0:1.0: 1 port detected Jun 12 13:54:03 volumiodvs2 kernel: dwc_otg: FIQ enabled Jun 12 13:54:03 volumiodvs2 kernel: dwc_otg: NAK holdoff enabled Jun 12 13:54:03 volumiodvs2 kernel: dwc_otg: FIQ split-transaction FSM enabled Jun 12 13:54:03 volumiodvs2 kernel: Module dwc_common_port init Jun 12 13:54:03 volumiodvs2 kernel: usbcore: registered new interface driver usb-storage Jun 12 13:54:03 volumiodvs2 kernel: mousedev: PS/2 mouse device common for all mice Jun 12 13:54:03 volumiodvs2 kernel: sdhci: Secure Digital Host Controller Interface driver Jun 12 13:54:03 volumiodvs2 kernel: sdhci: Copyright(c) Pierre Ossman Jun 12 13:54:03 volumiodvs2 kernel: sdhci-pltfm: SDHCI platform and OF driver helper Jun 12 13:54:03 volumiodvs2 kernel: ledtrig-cpu: registered to indicate activity on CPUs Jun 12 13:54:03 volumiodvs2 kernel: hid: raw HID events driver (C) Jiri Kosina Jun 12 13:54:03 volumiodvs2 kernel: usbcore: registered new interface driver usbhid Jun 12 13:54:03 volumiodvs2 kernel: usbhid: USB HID core driver Jun 12 13:54:03 volumiodvs2 kernel: Initializing XFRM netlink socket Jun 12 13:54:03 volumiodvs2 kernel: NET: Registered PF_PACKET protocol family Jun 12 13:54:03 volumiodvs2 kernel: Key type dns_resolver registered Jun 12 13:54:03 volumiodvs2 kernel: Registering SWP/SWPB emulation handler Jun 12 13:54:03 volumiodvs2 kernel: registered taskstats version 1 Jun 12 13:54:03 volumiodvs2 kernel: Loading compiled-in X.509 certificates Jun 12 13:54:03 volumiodvs2 kernel: Key type .fscrypt registered Jun 12 13:54:03 volumiodvs2 kernel: Key type fscrypt-provisioning registered Jun 12 13:54:03 volumiodvs2 kernel: uart-pl011 3f201000.serial: cts_event_workaround enabled Jun 12 13:54:03 volumiodvs2 kernel: 3f201000.serial: ttyAMA1 at MMIO 0x3f201000 (irq = 114, base_baud = 0) is a PL011 rev2 Jun 12 13:54:03 volumiodvs2 kernel: serial serial0: tty port ttyAMA1 registered Jun 12 13:54:03 volumiodvs2 kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Jun 12 13:54:03 volumiodvs2 kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Jun 12 13:54:03 volumiodvs2 kernel: mmc-bcm2835 3f300000.mmcnr: mmc_debug:0 mmc_debug2:0 Jun 12 13:54:03 volumiodvs2 kernel: mmc-bcm2835 3f300000.mmcnr: DMA channel allocated Jun 12 13:54:03 volumiodvs2 kernel: sdhost: log_buf @ 7ab99586 (f4107000) Jun 12 13:54:03 volumiodvs2 kernel: mmc0: sdhost-bcm2835 loaded - DMA enabled (>1) Jun 12 13:54:03 volumiodvs2 kernel: of_cfs_init Jun 12 13:54:03 volumiodvs2 kernel: of_cfs_init: OK Jun 12 13:54:03 volumiodvs2 kernel: Freeing unused kernel image (initmem) memory: 1024K Jun 12 13:54:03 volumiodvs2 kernel: Indeed it is in host mode hprt0 = 00021501 Jun 12 13:54:03 volumiodvs2 kernel: mmc0: host does not support reading read-only switch, assuming write-enable Jun 12 13:54:03 volumiodvs2 kernel: mmc0: new high speed SDHC card at address aaaa Jun 12 13:54:03 volumiodvs2 kernel: mmcblk0: mmc0:aaaa SC16G 14.8 GiB Jun 12 13:54:03 volumiodvs2 kernel: mmcblk0: p1 p2 p3 Jun 12 13:54:03 volumiodvs2 kernel: mmcblk0: mmc0:aaaa SC16G 14.8 GiB (quirks 0x00004000) Jun 12 13:54:03 volumiodvs2 kernel: mmc1: new high speed SDIO card at address 0001 Jun 12 13:54:03 volumiodvs2 kernel: Run /init as init process Jun 12 13:54:03 volumiodvs2 kernel: with arguments: Jun 12 13:54:03 volumiodvs2 kernel: /init Jun 12 13:54:03 volumiodvs2 kernel: splash Jun 12 13:54:03 volumiodvs2 kernel: nodebug Jun 12 13:54:03 volumiodvs2 kernel: with environment: Jun 12 13:54:03 volumiodvs2 kernel: HOME=/ Jun 12 13:54:03 volumiodvs2 kernel: TERM=linux Jun 12 13:54:03 volumiodvs2 kernel: imgpart=UUID=826680f7-a407-4ab9-8bd5-1855bda526fd Jun 12 13:54:03 volumiodvs2 kernel: imgfile=/volumio_current.sqsh Jun 12 13:54:03 volumiodvs2 kernel: bootpart=UUID=FD90-ED9E Jun 12 13:54:03 volumiodvs2 kernel: datapart=UUID=fecb0823-2e5b-4bba-9498-dd37b5084148 Jun 12 13:54:03 volumiodvs2 kernel: uuidconfig=cmdline.txt Jun 12 13:54:03 volumiodvs2 kernel: pcie_aspm=off Jun 12 13:54:03 volumiodvs2 kernel: pci=pcie_bus_safe Jun 12 13:54:03 volumiodvs2 kernel: bootdelay=7 Jun 12 13:54:03 volumiodvs2 kernel: use_kmsg=no Jun 12 13:54:03 volumiodvs2 kernel: usb 1-1: new high-speed USB device number 2 using dwc_otg Jun 12 13:54:03 volumiodvs2 kernel: Indeed it is in host mode hprt0 = 00001101 Jun 12 13:54:03 volumiodvs2 kernel: usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00 Jun 12 13:54:03 volumiodvs2 kernel: usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Jun 12 13:54:03 volumiodvs2 kernel: hub 1-1:1.0: USB hub found Jun 12 13:54:03 volumiodvs2 kernel: hub 1-1:1.0: 5 ports detected Jun 12 13:54:03 volumiodvs2 kernel: usb 1-1.1: new high-speed USB device number 3 using dwc_otg Jun 12 13:54:03 volumiodvs2 kernel: usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00 Jun 12 13:54:03 volumiodvs2 kernel: usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Jun 12 13:54:03 volumiodvs2 kernel: smsc95xx v2.0.0 Jun 12 13:54:03 volumiodvs2 kernel: SMSC LAN8700 usb-001:003:01: attached PHY driver (mii_bus:phy_addr=usb-001:003:01, irq=199) Jun 12 13:54:03 volumiodvs2 kernel: smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:e3:0a:13 Jun 12 13:54:03 volumiodvs2 kernel: fuse: init (API version 7.37) Jun 12 13:54:03 volumiodvs2 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Jun 12 13:54:03 volumiodvs2 kernel: usbcore: registered new interface driver uas Jun 12 13:54:03 volumiodvs2 kernel: EXT4-fs (mmcblk0p2): recovery complete Jun 12 13:54:03 volumiodvs2 kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none. Jun 12 13:54:03 volumiodvs2 kernel: loop0: detected capacity change from 0 to 979240 Jun 12 13:54:03 volumiodvs2 kernel: EXT4-fs (mmcblk0p3): recovery complete Jun 12 13:54:03 volumiodvs2 kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Quota mode: none. Jun 12 13:54:03 volumiodvs2 systemd[1]: System time before build time, advancing clock. Jun 12 13:54:03 volumiodvs2 kernel: NET: Registered PF_INET6 protocol family Jun 12 13:54:03 volumiodvs2 kernel: Segment Routing with IPv6 Jun 12 13:54:03 volumiodvs2 kernel: In-situ OAM (IOAM) with IPv6 Jun 12 13:54:03 volumiodvs2 systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) Jun 12 13:54:03 volumiodvs2 systemd[1]: Detected architecture arm. Jun 12 13:54:03 volumiodvs2 systemd[1]: Set hostname to . Jun 12 13:54:03 volumiodvs2 systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Jun 12 13:54:03 volumiodvs2 systemd[1]: Listening on Journal Socket (/dev/log). Jun 12 13:54:03 volumiodvs2 systemd[1]: Created slice system-getty.slice. Jun 12 13:54:03 volumiodvs2 systemd[1]: Listening on udev Control Socket. Jun 12 13:54:03 volumiodvs2 systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. Jun 12 13:54:03 volumiodvs2 systemd[1]: Listening on fsck to fsckd communication Socket. Jun 12 13:54:03 volumiodvs2 systemd[1]: Reached target System Time Synchronized. Jun 12 13:54:03 volumiodvs2 kernel: i2c_dev: i2c /dev entries driver Jun 12 13:54:03 volumiodvs2 systemd-journald[323]: Journal started Jun 12 13:54:03 volumiodvs2 systemd-journald[323]: Runtime journal (/run/log/journal/c28a768762e55f60d289ca8f665f5f47) is 7.5M, max 30.0M, 22.5M free. Jun 12 13:54:03 volumiodvs2 systemd-modules-load[319]: Inserted module 'i2c_dev' Jun 12 13:54:03 volumiodvs2 fake-hwclock[313]: Thu Jun 12 11:54:03 UTC 2025 Jun 12 13:54:03 volumiodvs2 systemd[1]: dynamicswap.service: Succeeded. Jun 12 13:54:03 volumiodvs2 systemd[1]: Started Apply Kernel Variables. Jun 12 13:54:03 volumiodvs2 systemd[1]: Started Create System Users. Jun 12 13:54:03 volumiodvs2 systemd[1]: Starting Create Static Device Nodes in /dev... Jun 12 13:54:03 volumiodvs2 systemd[1]: Started Create Static Device Nodes in /dev. Jun 12 13:54:03 volumiodvs2 systemd[1]: Reached target Local File Systems (Pre). Jun 12 13:54:03 volumiodvs2 systemd[1]: Mounting /var/spool/cups... Jun 12 13:54:03 volumiodvs2 systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Jun 12 13:54:03 volumiodvs2 systemd[1]: Mounting /tmp... Jun 12 13:54:03 volumiodvs2 systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Jun 12 13:54:03 volumiodvs2 systemd[1]: Mounting /var/log... Jun 12 13:54:03 volumiodvs2 systemd[1]: Starting udev Kernel Device Manager... Jun 12 13:54:03 volumiodvs2 systemd[1]: Started udev Coldplug all Devices. Jun 12 13:54:03 volumiodvs2 systemd[1]: Mounted /var/spool/cups. Jun 12 13:54:03 volumiodvs2 systemd[1]: Mounted /tmp. Jun 12 13:54:03 volumiodvs2 systemd[1]: Mounted /var/log. Jun 12 13:54:03 volumiodvs2 systemd[1]: Starting Flush Journal to Persistent Storage... Jun 12 13:54:03 volumiodvs2 systemd[1]: Mounting /var/spool/cups/tmp... Jun 12 13:54:03 volumiodvs2 systemd[1]: Starting Helper to synchronize boot up for ifupdown... Jun 12 13:54:03 volumiodvs2 systemd[1]: Mounted /var/spool/cups/tmp. Jun 12 13:54:03 volumiodvs2 systemd-udevd[352]: Network interface NamePolicy= disabled on kernel command line, ignoring. Jun 12 13:54:03 volumiodvs2 systemd-journald[323]: Runtime journal (/run/log/journal/c28a768762e55f60d289ca8f665f5f47) is 7.5M, max 30.0M, 22.5M free. Jun 12 13:54:03 volumiodvs2 systemd[1]: Started Flush Journal to Persistent Storage. Jun 12 13:54:03 volumiodvs2 systemd[1]: Started udev Kernel Device Manager. Jun 12 13:54:03 volumiodvs2 systemd[1]: Starting Show Plymouth Boot Screen... Jun 12 13:54:03 volumiodvs2 systemd[1]: plymouth-start.service: Succeeded. Jun 12 13:54:03 volumiodvs2 systemd[1]: Started Show Plymouth Boot Screen. Jun 12 13:54:03 volumiodvs2 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jun 12 13:54:03 volumiodvs2 systemd[1]: Reached target Local Encrypted Volumes. Jun 12 13:54:03 volumiodvs2 systemd[1]: Reached target Paths. Jun 12 13:54:03 volumiodvs2 systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Jun 12 13:54:04 volumiodvs2 kernel: rpi-gpiomem 3f200000.gpiomem: window base 0x3f200000 size 0x00001000 Jun 12 13:54:04 volumiodvs2 kernel: rpi-gpiomem 3f200000.gpiomem: initialised 1 regions as /dev/gpiomem Jun 12 13:54:04 volumiodvs2 kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Jun 12 13:54:04 volumiodvs2 kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Jun 12 13:54:04 volumiodvs2 kernel: [vc_sm_connected_init]: start Jun 12 13:54:04 volumiodvs2 kernel: mc: Linux media interface: v0.10 Jun 12 13:54:04 volumiodvs2 kernel: [vc_sm_connected_init]: installed successfully Jun 12 13:54:04 volumiodvs2 kernel: videodev: Linux video capture interface: v2.00 Jun 12 13:54:04 volumiodvs2 systemd[1]: Found device /dev/disk/by-uuid/FD90-ED9E. Jun 12 13:54:04 volumiodvs2 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Jun 12 13:54:04 volumiodvs2 kernel: Bluetooth: Core ver 2.22 Jun 12 13:54:04 volumiodvs2 kernel: NET: Registered PF_BLUETOOTH protocol family Jun 12 13:54:04 volumiodvs2 kernel: Bluetooth: HCI device and connection manager initialized Jun 12 13:54:04 volumiodvs2 kernel: Bluetooth: HCI socket layer initialized Jun 12 13:54:04 volumiodvs2 kernel: Bluetooth: L2CAP socket layer initialized Jun 12 13:54:04 volumiodvs2 kernel: Bluetooth: SCO socket layer initialized Jun 12 13:54:04 volumiodvs2 kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Jun 12 13:54:04 volumiodvs2 kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Jun 12 13:54:04 volumiodvs2 kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Jun 12 13:54:04 volumiodvs2 kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Jun 12 13:54:04 volumiodvs2 kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Jun 12 13:54:04 volumiodvs2 kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Jun 12 13:54:04 volumiodvs2 kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jun 12 13:54:04 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jun 12 13:54:04 volumiodvs2 kernel: Bluetooth: HCI UART driver ver 2.3 Jun 12 13:54:04 volumiodvs2 kernel: Bluetooth: HCI UART protocol H4 registered Jun 12 13:54:04 volumiodvs2 kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Jun 12 13:54:04 volumiodvs2 kernel: Bluetooth: HCI UART protocol Broadcom registered Jun 12 13:54:04 volumiodvs2 kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Jun 12 13:54:04 volumiodvs2 kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Jun 12 13:54:05 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Jun 12 13:54:05 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Jun 12 13:54:05 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Jun 12 13:54:05 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Jun 12 13:54:05 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jun 12 13:54:05 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jun 12 13:54:05 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jun 12 13:54:05 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jun 12 13:54:05 volumiodvs2 kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Jun 12 13:54:05 volumiodvs2 systemd[1]: Starting File System Check on /dev/disk/by-uuid/FD90-ED9E... Jun 12 13:54:05 volumiodvs2 kernel: uart-pl011 3f201000.serial: no DMA platform data Jun 12 13:54:05 volumiodvs2 systemd[1]: Started File System Check Daemon to report status. Jun 12 13:54:05 volumiodvs2 systemd-udevd[360]: Using default interface naming scheme 'v240'. Jun 12 13:54:05 volumiodvs2 systemd-udevd[360]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jun 12 13:54:05 volumiodvs2 kernel: Bluetooth: hci0: BCM: chip id 94 Jun 12 13:54:05 volumiodvs2 kernel: Bluetooth: hci0: BCM: features 0x2e Jun 12 13:54:05 volumiodvs2 kernel: Bluetooth: hci0: BCM43430A1 Jun 12 13:54:05 volumiodvs2 kernel: Bluetooth: hci0: BCM43430A1 (001.002.009) build 0000 Jun 12 13:54:05 volumiodvs2 kernel: Bluetooth: hci0: BCM43430A1 'brcm/BCM43430A1.hcd' Patch Jun 12 13:54:05 volumiodvs2 systemd-fsck[437]: fsck.fat 4.1 (2017-01-24) Jun 12 13:54:05 volumiodvs2 systemd-fsck[437]: /dev/mmcblk0p1: 369 files, 134026/184582 clusters Jun 12 13:54:05 volumiodvs2 systemd[1]: Started File System Check on /dev/disk/by-uuid/FD90-ED9E. Jun 12 13:54:05 volumiodvs2 systemd-udevd[368]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jun 12 13:54:05 volumiodvs2 kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Jun 12 13:54:05 volumiodvs2 kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Jun 12 13:54:05 volumiodvs2 kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Jun 12 13:54:05 volumiodvs2 kernel: cfg80211: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Jun 12 13:54:05 volumiodvs2 kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Jun 12 13:54:06 volumiodvs2 kernel: brcmfmac: F1 signature read @0x18000000=0x1541a9a6 Jun 12 13:54:06 volumiodvs2 kernel: Bluetooth: hci0: BCM: features 0x2e Jun 12 13:54:06 volumiodvs2 kernel: Bluetooth: hci0: BCM43438A1 37.4MHz Raspberry Pi 3-0141 Jun 12 13:54:06 volumiodvs2 kernel: Bluetooth: hci0: BCM43430A1 (001.002.009) build 0508 Jun 12 13:54:06 volumiodvs2 kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1 Jun 12 13:54:06 volumiodvs2 kernel: usbcore: registered new interface driver brcmfmac Jun 12 13:54:06 volumiodvs2 kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Jul 19 2021 03:24:18 version 7.45.98 (TOB) (56df937 CY) FWID 01-8e14b897 Jun 12 13:54:06 volumiodvs2 systemd-udevd[361]: Using default interface naming scheme 'v240'. Jun 12 13:54:06 volumiodvs2 systemd-udevd[361]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jun 12 13:54:07 volumiodvs2 systemd[1]: Created slice system-bthelper.slice. Jun 12 13:54:07 volumiodvs2 systemd[1]: Condition check resulted in Huge Pages File System being skipped. Jun 12 13:54:07 volumiodvs2 systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Jun 12 13:54:07 volumiodvs2 systemd[1]: Starting Show Plymouth Boot Screen... Jun 12 13:54:07 volumiodvs2 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Jun 12 13:54:07 volumiodvs2 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Jun 12 13:54:07 volumiodvs2 systemd[1]: Mounting /boot... Jun 12 13:54:07 volumiodvs2 systemd[1]: Found device SMSC9512/9514 Fast Ethernet Adapter. Jun 12 13:54:07 volumiodvs2 systemd[1]: Mounted /boot. Jun 12 13:54:07 volumiodvs2 systemd[1]: Reached target Local File Systems. Jun 12 13:54:07 volumiodvs2 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Jun 12 13:54:07 volumiodvs2 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Jun 12 13:54:07 volumiodvs2 systemd[1]: Starting Preprocess NFS configuration... Jun 12 13:54:07 volumiodvs2 systemd[1]: Starting Create Volatile Files and Directories... Jun 12 13:54:07 volumiodvs2 systemd[1]: Started ifup for eth0. Jun 12 13:54:07 volumiodvs2 systemd[1]: Starting Load/Save RF Kill Switch Status... Jun 12 13:54:07 volumiodvs2 systemd[1]: plymouth-start.service: Succeeded. Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Show Plymouth Boot Screen. Jun 12 13:54:07 volumiodvs2 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jun 12 13:54:07 volumiodvs2 systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Load/Save RF Kill Switch Status. Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Helper to synchronize boot up for ifupdown. Jun 12 13:54:07 volumiodvs2 systemd[1]: plymouth-read-write.service: Succeeded. Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Jun 12 13:54:07 volumiodvs2 systemd[1]: nfs-config.service: Succeeded. Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Preprocess NFS configuration. Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Create Volatile Files and Directories. Jun 12 13:54:07 volumiodvs2 systemd[1]: Received SIGRTMIN+20 from PID 213 (plymouthd). Jun 12 13:54:07 volumiodvs2 systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Jun 12 13:54:07 volumiodvs2 systemd[1]: Starting RPC bind portmap service... Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Jun 12 13:54:07 volumiodvs2 systemd[1]: Starting Update UTMP about System Boot/Shutdown... Jun 12 13:54:07 volumiodvs2 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Jun 12 13:54:07 volumiodvs2 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Jun 12 13:54:07 volumiodvs2 systemd[1]: Reached target NFS client services. Jun 12 13:54:07 volumiodvs2 systemd[1]: Starting Raise network interfaces... Jun 12 13:54:07 volumiodvs2 systemd[1]: Started ifup for wlan0. Jun 12 13:54:07 volumiodvs2 kernel: 8021q: 802.1Q VLAN Support v1.8 Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Update UTMP about System Boot/Shutdown. Jun 12 13:54:07 volumiodvs2 systemd[1]: Reached target System Initialization. Jun 12 13:54:07 volumiodvs2 systemd[1]: Listening on D-Bus System Message Bus Socket. Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Daily apt download activities. Jun 12 13:54:07 volumiodvs2 systemd[1]: Listening on triggerhappy.socket. Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Daily Cleanup of Temporary Directories. Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Daily apt upgrade and clean activities. Jun 12 13:54:07 volumiodvs2 systemd[1]: Reached target Timers. Jun 12 13:54:07 volumiodvs2 systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Jun 12 13:54:07 volumiodvs2 systemd[1]: Reached target Sockets. Jun 12 13:54:07 volumiodvs2 systemd[1]: Reached target Basic System. Jun 12 13:54:07 volumiodvs2 systemd[1]: Started Volumio Iptables Module. Jun 12 13:54:07 volumiodvs2 systemd[1]: Starting Login Service... Jun 12 13:54:07 volumiodvs2 systemd[1]: Started UPnP Renderer front-end to MPD. Jun 12 13:54:07 volumiodvs2 systemd[1]: Starting Wireless Services... Jun 12 13:54:08 volumiodvs2 systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Jun 12 13:54:08 volumiodvs2 systemd[1]: Starting Configure Bluetooth Modems connected by UART... Jun 12 13:54:08 volumiodvs2 systemd[1]: Starting triggerhappy global hotkey daemon... Jun 12 13:54:08 volumiodvs2 systemd[1]: Started Volumio Log Rotation Service. Jun 12 13:54:08 volumiodvs2 systemd[1]: Started volumio-remote-updater.service. Jun 12 13:54:08 volumiodvs2 systemd[1]: Started Manage Sound Card State (restore and store). Jun 12 13:54:08 volumiodvs2 alsactl[638]: alsactl 1.1.8 daemon started Jun 12 13:54:08 volumiodvs2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 12 13:54:08 volumiodvs2 systemd[1]: Starting Save/Restore Sound Card State... Jun 12 13:54:08 volumiodvs2 systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Jun 12 13:54:08 volumiodvs2 systemd[1]: Starting dhcpcd on all interfaces... Jun 12 13:54:08 volumiodvs2 systemd[1]: Started D-Bus System Message Bus. Jun 12 13:54:08 volumiodvs2 thd[634]: Unable to parse trigger line: Jun 12 13:54:08 volumiodvs2 thd[634]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Jun 12 13:54:08 volumiodvs2 thd[634]: Unable to parse trigger line: Jun 12 13:54:08 volumiodvs2 thd[634]: Found socket passed from systemd Jun 12 13:54:08 volumiodvs2 sh[539]: eth0: waiting for carrier Jun 12 13:54:08 volumiodvs2 kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Jun 12 13:54:08 volumiodvs2 kernel: smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off Jun 12 13:54:08 volumiodvs2 systemd[1]: Starting WPA supplicant... Jun 12 13:54:08 volumiodvs2 dhcpcd[570]: eth0: waiting for carrier Jun 12 13:54:08 volumiodvs2 dhcpcd[650]: Not running dhcpcd because /etc/network/interfaces Jun 12 13:54:08 volumiodvs2 dhcpcd[650]: defines some interfaces that will use a Jun 12 13:54:08 volumiodvs2 dhcpcd[650]: DHCP client or static address Jun 12 13:54:08 volumiodvs2 sh[539]: eth0: carrier acquired Jun 12 13:54:08 volumiodvs2 sh[539]: DUID 00:01:00:01:2d:f2:1d:9a:b8:27:eb:2b:fa:ad Jun 12 13:54:08 volumiodvs2 sh[539]: eth0: IAID eb:e3:0a:13 Jun 12 13:54:08 volumiodvs2 sh[539]: eth0: adding address fe80::ba27:ebff:fee3:a13 Jun 12 13:54:08 volumiodvs2 sh[539]: ipv6_addaddr1: Permission denied Jun 12 13:54:08 volumiodvs2 sh[539]: eth0: soliciting a DHCP lease Jun 12 13:54:08 volumiodvs2 systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Jun 12 13:54:08 volumiodvs2 dhcpcd[570]: eth0: carrier acquired Jun 12 13:54:08 volumiodvs2 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Jun 12 13:54:08 volumiodvs2 dhcpcd[570]: DUID 00:01:00:01:2d:f2:1d:9a:b8:27:eb:2b:fa:ad Jun 12 13:54:08 volumiodvs2 systemd[1]: Started RPC bind portmap service. Jun 12 13:54:08 volumiodvs2 dhcpcd[570]: eth0: IAID eb:e3:0a:13 Jun 12 13:54:08 volumiodvs2 dhcpcd[570]: eth0: adding address fe80::ba27:ebff:fee3:a13 Jun 12 13:54:08 volumiodvs2 dhcpcd[570]: ipv6_addaddr1: Permission denied Jun 12 13:54:08 volumiodvs2 dhcpcd[570]: eth0: soliciting a DHCP lease Jun 12 13:54:08 volumiodvs2 systemd[1]: Started triggerhappy global hotkey daemon. Jun 12 13:54:08 volumiodvs2 systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Jun 12 13:54:08 volumiodvs2 systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Jun 12 13:54:08 volumiodvs2 systemd[1]: Failed to start dhcpcd on all interfaces. Jun 12 13:54:08 volumiodvs2 sh[539]: eth0: soliciting an IPv6 router Jun 12 13:54:08 volumiodvs2 dhcpcd[570]: eth0: soliciting an IPv6 router Jun 12 13:54:08 volumiodvs2 sh[539]: eth0: offered 192.168.1.151 from 192.168.1.1 Jun 12 13:54:08 volumiodvs2 dhcpcd[570]: eth0: offered 192.168.1.151 from 192.168.1.1 Jun 12 13:54:08 volumiodvs2 dhcpcd[570]: eth0: probing address 192.168.1.151/24 Jun 12 13:54:08 volumiodvs2 sh[539]: eth0: probing address 192.168.1.151/24 Jun 12 13:54:08 volumiodvs2 systemd[1]: Reached target Remote File Systems (Pre). Jun 12 13:54:08 volumiodvs2 systemd[1]: Reached target Remote File Systems. Jun 12 13:54:08 volumiodvs2 systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Jun 12 13:54:08 volumiodvs2 systemd-logind[625]: New seat seat0. Jun 12 13:54:08 volumiodvs2 systemd[1]: Reached target RPC Port Mapper. Jun 12 13:54:08 volumiodvs2 systemd[1]: hciuart.service: Succeeded. Jun 12 13:54:08 volumiodvs2 systemd[1]: Started Configure Bluetooth Modems connected by UART. Jun 12 13:54:08 volumiodvs2 systemd[1]: Starting Raspberry Pi bluetooth helper... Jun 12 13:54:08 volumiodvs2 ifup[573]: ifup: waiting for lock on /run/network/ifstate.wlan0 Jun 12 13:54:08 volumiodvs2 sh[574]: wlan0=wlan0 Jun 12 13:54:08 volumiodvs2 avahi-daemon[676]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Jun 12 13:54:08 volumiodvs2 avahi-daemon[676]: Successfully dropped root privileges. Jun 12 13:54:08 volumiodvs2 avahi-daemon[676]: avahi-daemon 0.7 starting up. Jun 12 13:54:09 volumiodvs2 bthelper[695]: Raspberry Pi BDADDR already set Jun 12 13:54:09 volumiodvs2 systemd[1]: Started Login Service. Jun 12 13:54:09 volumiodvs2 systemd[1]: Started Raspberry Pi bluetooth helper. Jun 12 13:54:09 volumiodvs2 avahi-daemon[676]: Successfully called chroot(). Jun 12 13:54:09 volumiodvs2 avahi-daemon[676]: Successfully dropped remaining capabilities. Jun 12 13:54:09 volumiodvs2 wpa_supplicant[662]: Successfully initialized wpa_supplicant Jun 12 13:54:09 volumiodvs2 avahi-daemon[676]: Loading service file /services/volumio.service. Jun 12 13:54:09 volumiodvs2 avahi-daemon[676]: Network interface enumeration completed. Jun 12 13:54:09 volumiodvs2 avahi-daemon[676]: Server startup complete. Host name is volumiodvs2.local. Local service cookie is 3401651668. Jun 12 13:54:09 volumiodvs2 avahi-daemon[676]: Service "VolumioDVS2" (/services/volumio.service) successfully established. Jun 12 13:54:09 volumiodvs2 systemd[1]: Started Save/Restore Sound Card State. Jun 12 13:54:09 volumiodvs2 systemd[1]: Started Raise network interfaces. Jun 12 13:54:09 volumiodvs2 systemd[1]: Started Avahi mDNS/DNS-SD Stack. Jun 12 13:54:09 volumiodvs2 systemd[1]: Started WPA supplicant. Jun 12 13:54:09 volumiodvs2 systemd[1]: Reached target Network. Jun 12 13:54:09 volumiodvs2 systemd[1]: Starting OpenBSD Secure Shell server... Jun 12 13:54:09 volumiodvs2 systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Jun 12 13:54:09 volumiodvs2 systemd[1]: Starting Network Time Service... Jun 12 13:54:09 volumiodvs2 systemd[1]: Starting Permit User Sessions... Jun 12 13:54:09 volumiodvs2 systemd[1]: Reached target Network is Online. Jun 12 13:54:09 volumiodvs2 systemd[1]: Starting Samba NMB Daemon... Jun 12 13:54:09 volumiodvs2 systemd[1]: Starting LSB: Brings up/down network automatically... Jun 12 13:54:09 volumiodvs2 systemd[1]: Starting /etc/rc.local Compatibility... Jun 12 13:54:09 volumiodvs2 systemd[1]: Reached target Sound Card. Jun 12 13:54:09 volumiodvs2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 12 13:54:09 volumiodvs2 systemd[1]: Starting Bluetooth service... Jun 12 13:54:09 volumiodvs2 systemd[1]: Started Permit User Sessions. Jun 12 13:54:10 volumiodvs2 systemd[1]: Started /etc/rc.local Compatibility. Jun 12 13:54:10 volumiodvs2 systemd[1]: Starting Hold until boot process finishes up... Jun 12 13:54:10 volumiodvs2 systemd[1]: Starting Terminate Plymouth Boot Screen... Jun 12 13:54:10 volumiodvs2 systemd[1]: Received SIGRTMIN+21 from PID 213 (plymouthd). Jun 12 13:54:10 volumiodvs2 systemd[1]: plymouth-quit-wait.service: Succeeded. Jun 12 13:54:10 volumiodvs2 systemd[1]: Started Hold until boot process finishes up. Jun 12 13:54:10 volumiodvs2 systemd[1]: plymouth-quit.service: Succeeded. Jun 12 13:54:10 volumiodvs2 systemd[1]: Started Terminate Plymouth Boot Screen. Jun 12 13:54:10 volumiodvs2 systemd[1]: Received SIGRTMIN+21 from PID 213 (plymouthd). Jun 12 13:54:10 volumiodvs2 volumio-remote-updater[637]: Error: No active session Jun 12 13:54:10 volumiodvs2 volumio-remote-updater[637]: [2025-06-12 13:54:10] [info] asio async_connect error: system:111 (Connection refused) Jun 12 13:54:10 volumiodvs2 volumio-remote-updater[637]: [2025-06-12 13:54:10] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jun 12 13:54:10 volumiodvs2 volumio-remote-updater[637]: [2025-06-12 13:54:10] [error] handle_connect error: Underlying Transport Error Jun 12 13:54:10 volumiodvs2 systemd[1]: Started Getty on tty1. Jun 12 13:54:10 volumiodvs2 systemd[1]: Reached target Login Prompts. Jun 12 13:54:10 volumiodvs2 ifplugd(eth0)[808]: ifplugd 0.28 initializing. Jun 12 13:54:10 volumiodvs2 ifplugd(eth0)[808]: Using interface eth0/B8:27:EB:E3:0A:13 with driver (version: 6.1.77-v7+) Jun 12 13:54:10 volumiodvs2 ifplugd(eth0)[808]: Using detection mode: SIOCETHTOOL Jun 12 13:54:10 volumiodvs2 ifplugd(eth0)[808]: Initialization complete, link beat detected. Jun 12 13:54:10 volumiodvs2 loadcpufreq[691]: Loading cpufreq kernel modules...done (none). Jun 12 13:54:10 volumiodvs2 systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Jun 12 13:54:10 volumiodvs2 systemd[1]: Starting LSB: set CPUFreq kernel parameters... Jun 12 13:54:10 volumiodvs2 systemd[1]: iptables.service: Succeeded. Jun 12 13:54:10 volumiodvs2 ifplugd(eth0)[808]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Jun 12 13:54:10 volumiodvs2 ntpd[753]: ntpd 4.2.8p12@1.3728-o (1): Starting Jun 12 13:54:10 volumiodvs2 ntpd[753]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Jun 12 13:54:10 volumiodvs2 volumio[627]: Could not open config: /tmp/upmpdcli.conf Jun 12 13:54:10 volumiodvs2 ntpd[816]: proto: precision = 1.458 usec (-19) Jun 12 13:54:10 volumiodvs2 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jun 12 13:54:10 volumiodvs2 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jun 12 13:54:10 volumiodvs2 bluetoothd[765]: Bluetooth daemon 5.50 Jun 12 13:54:10 volumiodvs2 ntpd[816]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jun 12 13:54:10 volumiodvs2 ntpd[816]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jun 12 13:54:10 volumiodvs2 ntpd[816]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 167 days ago Jun 12 13:54:10 volumiodvs2 ntpd[816]: Listen and drop on 0 v6wildcard [::]:123 Jun 12 13:54:10 volumiodvs2 ntpd[816]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jun 12 13:54:10 volumiodvs2 ntpd[816]: Listen normally on 2 lo 127.0.0.1:123 Jun 12 13:54:10 volumiodvs2 ntpd[816]: Listening on routing socket on fd #19 for interface updates Jun 12 13:54:10 volumiodvs2 ntpd[816]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 12 13:54:10 volumiodvs2 ntpd[816]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 12 13:54:10 volumiodvs2 systemd[1]: Started Network Time Service. Jun 12 13:54:10 volumiodvs2 bluetoothd[765]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Jun 12 13:54:10 volumiodvs2 systemd[1]: Started Bluetooth service. Jun 12 13:54:10 volumiodvs2 systemd[1]: Reached target Bluetooth. Jun 12 13:54:10 volumiodvs2 bluetoothd[765]: Starting SDP server Jun 12 13:54:10 volumiodvs2 bluetoothd[765]: Excluding (cli) sap Jun 12 13:54:10 volumiodvs2 ifplugd(eth0)[808]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Jun 12 13:54:10 volumiodvs2 sshd[819]: Server listening on 0.0.0.0 port 22. Jun 12 13:54:10 volumiodvs2 sshd[819]: Server listening on :: port 22. Jun 12 13:54:10 volumiodvs2 systemd[1]: Started OpenBSD Secure Shell server. Jun 12 13:54:10 volumiodvs2 cpufrequtils[810]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Jun 12 13:54:10 volumiodvs2 systemd[1]: Started LSB: set CPUFreq kernel parameters. Jun 12 13:54:11 volumiodvs2 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Jun 12 13:54:11 volumiodvs2 kernel: Bluetooth: BNEP filters: protocol multicast Jun 12 13:54:11 volumiodvs2 kernel: Bluetooth: BNEP socket layer initialized Jun 12 13:54:11 volumiodvs2 bluetoothd[765]: Bluetooth management interface 1.22 initialized Jun 12 13:54:11 volumiodvs2 kernel: Bluetooth: MGMT ver 1.22 Jun 12 13:54:11 volumiodvs2 dbus-daemon[651]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=765 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Jun 12 13:54:11 volumiodvs2 haveged[571]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Jun 12 13:54:11 volumiodvs2 haveged[571]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Jun 12 13:54:11 volumiodvs2 haveged[571]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00161 Jun 12 13:54:11 volumiodvs2 haveged[571]: haveged: fills: 0, generated: 0 Jun 12 13:54:11 volumiodvs2 bluetoothd[765]: Failed to set privacy: Rejected (0x0b) Jun 12 13:54:11 volumiodvs2 systemd[1]: Starting Hostname Service... Jun 12 13:54:11 volumiodvs2 dbus-daemon[651]: [system] Successfully activated service 'org.freedesktop.hostname1' Jun 12 13:54:11 volumiodvs2 systemd[1]: Started Hostname Service. Jun 12 13:54:11 volumiodvs2 ntpd[816]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jun 12 13:54:11 volumiodvs2 nmbd[771]: [2025/06/12 13:54:11.775351, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Jun 12 13:54:11 volumiodvs2 nmbd[771]: started asyncdns process 842 Jun 12 13:54:11 volumiodvs2 nmbd[771]: [2025/06/12 13:54:11.777744, 0] ../lib/util/become_daemon.c:149(daemon_status) Jun 12 13:54:11 volumiodvs2 nmbd[771]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Jun 12 13:54:11 volumiodvs2 nmbd[771]: [2025/06/12 13:54:11.777928, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Jun 12 13:54:11 volumiodvs2 nmbd[771]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jun 12 13:54:12 volumiodvs2 wireless.js[629]: Cleaning previous... Jun 12 13:54:12 volumiodvs2 sudo[850]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 12 13:54:12 volumiodvs2 sudo[850]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:12 volumiodvs2 systemd[1]: systemd-rfkill.service: Succeeded. Jun 12 13:54:12 volumiodvs2 sudo[850]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:12 volumiodvs2 sudo[852]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jun 12 13:54:12 volumiodvs2 sudo[852]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:12 volumiodvs2 ntpd[816]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jun 12 13:54:13 volumiodvs2 sudo[852]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:13 volumiodvs2 wireless.js[629]: Stopped aP Jun 12 13:54:13 volumiodvs2 wireless.js[629]: Wireless Networking DISABLED, not starting wireless flow Jun 12 13:54:13 volumiodvs2 systemd[1]: wireless.service: Succeeded. Jun 12 13:54:13 volumiodvs2 systemd[1]: Started Wireless Services. Jun 12 13:54:13 volumiodvs2 systemd[1]: Started Volumio Backend Module. Jun 12 13:54:13 volumiodvs2 systemd[1]: Started Volumio Cpu Tweaker. Jun 12 13:54:13 volumiodvs2 volumio-cpu-tweak[861]: Setting RT Priority for mpd Jun 12 13:54:13 volumiodvs2 volumio-cpu-tweak[861]: pid 35's current scheduling policy: SCHED_OTHER Jun 12 13:54:13 volumiodvs2 volumio-cpu-tweak[861]: pid 35's current scheduling priority: 0 Jun 12 13:54:13 volumiodvs2 volumio-cpu-tweak[861]: Setting MPD Affinity Jun 12 13:54:13 volumiodvs2 volumio-cpu-tweak[861]: pid 3's current affinity mask: f Jun 12 13:54:13 volumiodvs2 volumio-cpu-tweak[861]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jun 12 13:54:13 volumiodvs2 volumio-cpu-tweak[861]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jun 12 13:54:13 volumiodvs2 systemd[1]: volumio_cpu_tweak.service: Succeeded. Jun 12 13:54:13 volumiodvs2 sh[539]: eth0: leased 192.168.1.151 for 864000 seconds Jun 12 13:54:13 volumiodvs2 sh[539]: eth0: adding route to 192.168.1.0/24 Jun 12 13:54:13 volumiodvs2 sh[539]: eth0: adding default route via 192.168.1.1 Jun 12 13:54:13 volumiodvs2 dhcpcd[570]: eth0: leased 192.168.1.151 for 864000 seconds Jun 12 13:54:13 volumiodvs2 avahi-daemon[676]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.151. Jun 12 13:54:13 volumiodvs2 dhcpcd[570]: eth0: adding route to 192.168.1.0/24 Jun 12 13:54:13 volumiodvs2 avahi-daemon[676]: New relevant interface eth0.IPv4 for mDNS. Jun 12 13:54:13 volumiodvs2 dhcpcd[570]: eth0: adding default route via 192.168.1.1 Jun 12 13:54:13 volumiodvs2 avahi-daemon[676]: Registering new address record for 192.168.1.151 on eth0.IPv4. Jun 12 13:54:13 volumiodvs2 ntpd[816]: ntpd exiting on signal 15 (Terminated) Jun 12 13:54:13 volumiodvs2 systemd[1]: Stopping Network Time Service... Jun 12 13:54:13 volumiodvs2 systemd[1]: ntp.service: Succeeded. Jun 12 13:54:13 volumiodvs2 systemd[1]: Stopped Network Time Service. Jun 12 13:54:13 volumiodvs2 systemd[1]: Starting Network Time Service... Jun 12 13:54:13 volumiodvs2 ntpd[908]: ntpd 4.2.8p12@1.3728-o (1): Starting Jun 12 13:54:13 volumiodvs2 ntpd[908]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -c /run/ntp.conf.dhcp -u 103:103 Jun 12 13:54:13 volumiodvs2 systemd[1]: Started Network Time Service. Jun 12 13:54:13 volumiodvs2 sh[539]: forked to background, child pid 915 Jun 12 13:54:13 volumiodvs2 dhcpcd[570]: forked to background, child pid 915 Jun 12 13:54:13 volumiodvs2 ntpd[914]: proto: precision = 0.677 usec (-20) Jun 12 13:54:13 volumiodvs2 ntpd[914]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jun 12 13:54:13 volumiodvs2 ntpd[914]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jun 12 13:54:13 volumiodvs2 ntpd[914]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 167 days ago Jun 12 13:54:13 volumiodvs2 ntpd[914]: Listen and drop on 0 v6wildcard [::]:123 Jun 12 13:54:13 volumiodvs2 ntpd[914]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jun 12 13:54:13 volumiodvs2 ntpd[914]: Listen normally on 2 lo 127.0.0.1:123 Jun 12 13:54:13 volumiodvs2 ntpd[914]: Listen normally on 3 eth0 192.168.1.151:123 Jun 12 13:54:13 volumiodvs2 ntpd[914]: Listening on routing socket on fd #20 for interface updates Jun 12 13:54:13 volumiodvs2 ntpd[914]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 12 13:54:13 volumiodvs2 ntpd[914]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jun 12 13:54:13 volumiodvs2 ifplugd(eth0)[808]: client: ifup: interface eth0 already configured Jun 12 13:54:13 volumiodvs2 sh[539]: eth0=eth0 Jun 12 13:54:13 volumiodvs2 ifplugd(eth0)[808]: Program executed successfully. Jun 12 13:54:13 volumiodvs2 ifplugd[757]: Network Interface Plugging Daemon...start eth0...done. Jun 12 13:54:13 volumiodvs2 systemd[1]: Started LSB: Brings up/down network automatically. Jun 12 13:54:14 volumiodvs2 bthelper[695]: Changing power off succeeded Jun 12 13:54:14 volumiodvs2 bthelper[695]: [CHG] Controller B8:27:EB:49:A0:B9 Class: 0x0000041c Jun 12 13:54:14 volumiodvs2 bthelper[695]: Changing power on succeeded Jun 12 13:54:14 volumiodvs2 ntpd[914]: Soliciting pool server 192.33.96.102 Jun 12 13:54:15 volumiodvs2 volumio-remote-updater[637]: [2025-06-12 13:54:15] [connect] Successful connection Jun 12 13:54:15 volumiodvs2 ntpd[914]: Soliciting pool server 212.51.144.46 Jun 12 13:54:15 volumiodvs2 ntpd[914]: Soliciting pool server 192.33.214.47 Jun 12 13:54:16 volumiodvs2 volumio[860]: info: ------------------------------------------- Jun 12 13:54:16 volumiodvs2 volumio[860]: info: ----- Volumio3 ---- Jun 12 13:54:16 volumiodvs2 volumio[860]: info: ------------------------------------------- Jun 12 13:54:16 volumiodvs2 volumio[860]: info: ----- System startup ---- Jun 12 13:54:16 volumiodvs2 volumio[860]: info: ------------------------------------------- Jun 12 13:54:16 volumiodvs2 ntpd[914]: Soliciting pool server 62.12.173.12 Jun 12 13:54:16 volumiodvs2 ntpd[914]: Soliciting pool server 212.25.15.128 Jun 12 13:54:16 volumiodvs2 ntpd[914]: Soliciting pool server 193.33.30.39 Jun 12 13:54:16 volumiodvs2 systemd[1]: Started Samba NMB Daemon. Jun 12 13:54:16 volumiodvs2 nmbd[771]: [2025/06/12 13:54:16.797057, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 12 13:54:16 volumiodvs2 nmbd[771]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jun 12 13:54:16 volumiodvs2 systemd[1]: Starting Samba Winbind Daemon... Jun 12 13:54:16 volumiodvs2 nmbd[771]: [2025/06/12 13:54:16.814980, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Jun 12 13:54:16 volumiodvs2 nmbd[771]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.151 for name WORKGROUP<1d>. Jun 12 13:54:16 volumiodvs2 nmbd[771]: This response was from IP 192.168.1.214, reporting an IP address of 192.168.1.214. Jun 12 13:54:17 volumiodvs2 winbindd[956]: [2025/06/12 13:54:17.240871, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jun 12 13:54:17 volumiodvs2 winbindd[956]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jun 12 13:54:17 volumiodvs2 winbindd[956]: [2025/06/12 13:54:17.265498, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 12 13:54:17 volumiodvs2 winbindd[956]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jun 12 13:54:17 volumiodvs2 systemd[1]: Started Samba Winbind Daemon. Jun 12 13:54:17 volumiodvs2 systemd[1]: Starting Samba SMB Daemon... Jun 12 13:54:17 volumiodvs2 volumio[860]: info: MYVOLUMIO Environment detected Jun 12 13:54:17 volumiodvs2 ntpd[914]: Soliciting pool server 195.141.190.190 Jun 12 13:54:17 volumiodvs2 ntpd[914]: Soliciting pool server 84.16.67.12 Jun 12 13:54:17 volumiodvs2 ntpd[914]: Soliciting pool server 79.110.235.11 Jun 12 13:54:17 volumiodvs2 ntpd[914]: Soliciting pool server 193.134.29.12 Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Plugin folders cleanup Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Scanning into folder /volumio/app/plugins/ Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Scanning category audio_interface Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Scanning category miscellanea Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Scanning category music_service Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Scanning category plugins.json Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Scanning category system_controller Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Scanning category user_interface Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Scanning into folder /data/plugins/ Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Scanning category music_service Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Plugin folders cleanup completed Jun 12 13:54:17 volumiodvs2 volumio[860]: info: ------------------------------------------- Jun 12 13:54:17 volumiodvs2 volumio[860]: info: ----- Core plugins startup ---- Jun 12 13:54:17 volumiodvs2 volumio[860]: info: ------------------------------------------- Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Loading plugins from folder /volumio/app/plugins/ Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Adding plugin upnp to MyMusic Plugins Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Loading plugins from folder /data/plugins/ Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Loading plugin "system"... Jun 12 13:54:17 volumiodvs2 volumio[860]: info: Loading plugin "appearance"... Jun 12 13:54:17 volumiodvs2 smbd[961]: [2025/06/12 13:54:17.904060, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 12 13:54:17 volumiodvs2 systemd[1]: Started Samba SMB Daemon. Jun 12 13:54:17 volumiodvs2 smbd[961]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jun 12 13:54:17 volumiodvs2 systemd[1]: Reached target Multi-User System. Jun 12 13:54:17 volumiodvs2 systemd[1]: Reached target Graphical Interface. Jun 12 13:54:17 volumiodvs2 systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 12 13:54:18 volumiodvs2 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 12 13:54:18 volumiodvs2 systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 12 13:54:18 volumiodvs2 systemd[1]: Startup finished in 15.729s (kernel) + 17.742s (userspace) = 33.471s. Jun 12 13:54:18 volumiodvs2 ntpd[914]: Soliciting pool server 195.186.4.100 Jun 12 13:54:18 volumiodvs2 ntpd[914]: Soliciting pool server 91.235.212.22 Jun 12 13:54:18 volumiodvs2 ntpd[914]: Soliciting pool server 82.197.162.18 Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Loading plugin "network"... Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Refreshing Cached IP Addresses Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Loading plugin "services"... Jun 12 13:54:19 volumiodvs2 sudo[976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Loading plugin "alsa_controller"... Jun 12 13:54:19 volumiodvs2 sudo[976]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:19 volumiodvs2 sudo[978]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 12 13:54:19 volumiodvs2 sudo[978]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:19 volumiodvs2 sudo[976]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:19 volumiodvs2 sudo[978]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:19 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Loading plugin "wizard"... Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Loading plugin "networkfs"... Jun 12 13:54:19 volumiodvs2 ntpd[914]: Soliciting pool server 81.94.123.16 Jun 12 13:54:19 volumiodvs2 ntpd[914]: Soliciting pool server 91.216.229.123 Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Starting Udev Watcher for removable devices Jun 12 13:54:19 volumiodvs2 sudo[986]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=user_musica,password=Password0,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.90/music /mnt/NAS/music Jun 12 13:54:19 volumiodvs2 sudo[986]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Ignoring mount for partition: boot Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Ignoring mount for partition: volumio Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Ignoring mount for partition: volumio_data Jun 12 13:54:19 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Loading plugin "volumio_command_line_client"... Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Loading plugin "upnp"... Jun 12 13:54:19 volumiodvs2 volumio[860]: info: [1749729259826] Starting Upmpd Daemon Jun 12 13:54:19 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Loading plugin "my_music"... Jun 12 13:54:19 volumiodvs2 volumio[860]: info: Loading plugin "mpd"... Jun 12 13:54:19 volumiodvs2 kernel: Key type cifs.spnego registered Jun 12 13:54:19 volumiodvs2 kernel: Key type cifs.idmap registered Jun 12 13:54:19 volumiodvs2 kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Jun 12 13:54:19 volumiodvs2 kernel: CIFS: Attempting to mount \\192.168.1.90\music Jun 12 13:54:20 volumiodvs2 sudo[986]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:20 volumiodvs2 volumio[860]: info: Loading plugin "upnp_browser"... Jun 12 13:54:20 volumiodvs2 ntpd[914]: Soliciting pool server 85.195.224.28 Jun 12 13:54:20 volumiodvs2 ntpd[914]: Soliciting pool server 2001:1600:3:6::123 Jun 12 13:54:20 volumiodvs2 volumio[860]: info: Loading plugin "alarm-clock"... Jun 12 13:54:21 volumiodvs2 volumio[860]: info: Loading plugin "airplay_emulation"... Jun 12 13:54:21 volumiodvs2 volumio[860]: info: Starting Shairport Sync Jun 12 13:54:21 volumiodvs2 volumio[860]: info: Loading plugin "last_100"... Jun 12 13:54:21 volumiodvs2 volumio[860]: info: Loading plugin "webradio"... Jun 12 13:54:21 volumiodvs2 volumio[860]: info: Loading plugin "i2s_dacs"... Jun 12 13:54:21 volumiodvs2 volumio[860]: info: Loading plugin "volumiodiscovery"... Jun 12 13:54:21 volumiodvs2 volumio[860]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 12 13:54:21 volumiodvs2 volumio[860]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 12 13:54:21 volumiodvs2 volumio[860]: *** WARNING *** For more information see Jun 12 13:54:21 volumiodvs2 node[860]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 12 13:54:21 volumiodvs2 volumio[860]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 12 13:54:21 volumiodvs2 volumio[860]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 12 13:54:21 volumiodvs2 volumio[860]: *** WARNING *** For more information see Jun 12 13:54:21 volumiodvs2 node[860]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 12 13:54:21 volumiodvs2 node[860]: *** WARNING *** For more information see Jun 12 13:54:21 volumiodvs2 node[860]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 12 13:54:21 volumiodvs2 node[860]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 12 13:54:21 volumiodvs2 node[860]: *** WARNING *** For more information see Jun 12 13:54:21 volumiodvs2 volumio[860]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 12 13:54:21 volumiodvs2 volumio[860]: info: Discovery: Started advertising with name: VolumioDVS2 Jun 12 13:54:21 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 12 13:54:21 volumiodvs2 volumio[860]: info: Loading plugin "spop"... Jun 12 13:54:45 volumiodvs2 ntpd[914]: receive: Unexpected origin timestamp 0xebf53e6d.b09f0778 does not match aorg 0000000000.00000000 from server@193.134.29.12 xmt 0xebf53e85.7628d2a5 Jun 12 13:54:45 volumiodvs2 ntpd[914]: receive: Unexpected origin timestamp 0xebf53e6d.b09cc644 does not match aorg 0000000000.00000000 from server@195.186.4.100 xmt 0xebf53e85.7659ecff Jun 12 13:54:45 volumiodvs2 ntpd[914]: receive: Unexpected origin timestamp 0xebf53e6d.b0a194a4 does not match aorg 0000000000.00000000 from server@84.16.67.12 xmt 0xebf53e85.76350279 Jun 12 13:54:45 volumiodvs2 ntpd[914]: receive: Unexpected origin timestamp 0xebf53e6d.b096367a does not match aorg 0000000000.00000000 from server@91.216.229.123 xmt 0xebf53e85.7675dc94 Jun 12 13:54:45 volumiodvs2 ntpd[914]: receive: Unexpected origin timestamp 0xebf53e6d.b0a4336a does not match aorg 0000000000.00000000 from server@193.33.30.39 xmt 0xebf53e85.51f8eb87 Jun 12 13:54:45 volumiodvs2 ntpd[914]: receive: Unexpected origin timestamp 0xebf53e6d.b08e5c7c does not match aorg 0000000000.00000000 from server@85.195.224.28 xmt 0xebf53e85.76cede2c Jun 12 13:54:45 volumiodvs2 ntpd[914]: receive: Unexpected origin timestamp 0xebf53e6d.b09a76bc does not match aorg 0000000000.00000000 from server@82.197.162.18 xmt 0xebf53e85.76df49de Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Loading plugin "outputs"... Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Loading plugin "albumart"... Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Plugin example_plugin is not enabled Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Loading plugin "inputs"... Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Loading plugin "updater_comm"... Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Plugin mpdemulation is not enabled Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Loading plugin "rest_api"... Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Loading plugin "websocket"... Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Starting Socket.io Server version 2.3.0 Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Loading plugin "minidlna"... Jun 12 13:54:47 volumiodvs2 volumio[860]: Forking 3 albumart workers Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Applying required configuration parameters for plugin minidlna Jun 12 13:54:47 volumiodvs2 volumio[860]: info: Loading i18n strings for locale it Jun 12 13:54:47 volumiodvs2 volumio[860]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Jun 12 13:54:47 volumiodvs2 volumio[860]: Updating browse sources language Jun 12 13:54:47 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::initPlayerControls Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: Express server listening on port 3000 Jun 12 13:54:48 volumiodvs2 volumio[860]: [Metrics] WebUI: 9s 318.85ms Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreStateMachine::resetVolumioState Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreStateMachine::getcurrentVolume Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioRetrievevolume Jun 12 13:54:48 volumiodvs2 volumio[860]: verbose: New Socket.io Connection to 192.168.1.151 from 192.168.1.94 UA: Mozilla/5.0 (Linux x86_64) AppleWebKit/610.1 (KHTML, like Gecko) JavaFX/8.0 Safari/610.1 Engine version: 3 Transport: polling Total Clients: 1 Jun 12 13:54:48 volumiodvs2 volumio[860]: Starting albumart workers Jun 12 13:54:48 volumiodvs2 volumio[860]: Starting albumart workers Jun 12 13:54:48 volumiodvs2 volumio[860]: verbose: New Socket.io Connection to 192.168.1.151 from 192.168.1.94 UA: Mozilla/5.0 (Linux x86_64) AppleWebKit/610.1 (KHTML, like Gecko) JavaFX/8.0 Safari/610.1 Engine version: 3 Transport: polling Total Clients: 2 Jun 12 13:54:48 volumiodvs2 volumio[860]: verbose: New Socket.io Connection to 192.168.1.151 from 192.168.1.219 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jun 12 13:54:48 volumiodvs2 volumio[860]: verbose: New Socket.io Connection to 192.168.1.151 from 192.168.1.94 UA: Mozilla/5.0 (Linux x86_64) AppleWebKit/610.1 (KHTML, like Gecko) JavaFX/8.0 Safari/610.1 Engine version: 3 Transport: polling Total Clients: 4 Jun 12 13:54:48 volumiodvs2 volumio[860]: Starting albumart workers Jun 12 13:54:48 volumiodvs2 volumio[860]: verbose: New Socket.io Connection to 192.168.1.151 from 192.168.1.219 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jun 12 13:54:48 volumiodvs2 volumio[860]: verbose: New Socket.io Connection to 192.168.1.151 from 192.168.1.94 UA: Mozilla/5.0 (Linux x86_64) AppleWebKit/610.1 (KHTML, like Gecko) JavaFX/8.0 Safari/610.1 Engine version: 3 Transport: polling Total Clients: 6 Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioGetState Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 12 13:54:48 volumiodvs2 volumio[860]: info: Reloading queue from file Jun 12 13:54:48 volumiodvs2 volumio[860]: info: Setting Device type: Raspberry PI Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreStateMachine::setRepeat null single undefined Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreStateMachine::pushState Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioPushState Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreStateMachine::setRandom false Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreStateMachine::pushState Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 12 13:54:48 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioPushState Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Listing playlists Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Listing playlists Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Completed loading Core Plugins Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Preparing to generate the ALSA configuration file Jun 12 13:54:49 volumiodvs2 volumio[860]: info: VolumeController:: Volume=100 Mute =false Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreStateMachine::pushState Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioPushState Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreStateMachine::updateTrackBlock Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrackBlock Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioRetrievevolume Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Asound.conf file unchanged, so no further update is needed Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Output device has changed, restarting MPD Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Output device has changed, restarting Shairport Sync Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 12 13:54:49 volumiodvs2 sudo[1054]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 12 13:54:49 volumiodvs2 sudo[1054]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:49 volumiodvs2 sudo[1055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 12 13:54:49 volumiodvs2 sudo[1055]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 12 13:54:49 volumiodvs2 volumio[860]: info: ___________ START PLUGINS ___________ Jun 12 13:54:49 volumiodvs2 volumio[860]: info: ControllerMpd::onStart: Initializing MPD Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Creating MPD Configuration file Jun 12 13:54:49 volumiodvs2 sudo[1054]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 12 13:54:49 volumiodvs2 volumio[860]: info: [1749729289361] CoreMusicLibrary::Adding element Server multimediali Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 12 13:54:49 volumiodvs2 sudo[1063]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 12 13:54:49 volumiodvs2 sudo[1063]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 12 13:54:49 volumiodvs2 sudo[1064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 12 13:54:49 volumiodvs2 sudo[1064]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:49 volumiodvs2 sudo[1063]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:49 volumiodvs2 systemd[1]: Listening on mpd.socket. Jun 12 13:54:49 volumiodvs2 systemd[1]: Starting Music Player Daemon... Jun 12 13:54:49 volumiodvs2 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jun 12 13:54:49 volumiodvs2 systemd[1]: mpd.service: Succeeded. Jun 12 13:54:49 volumiodvs2 systemd[1]: Stopped Music Player Daemon. Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 12 13:54:49 volumiodvs2 systemd[1]: Starting Music Player Daemon... Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 12 13:54:49 volumiodvs2 volumio[860]: info: [1749729289566] CoreMusicLibrary::Adding element Last_100 Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 12 13:54:49 volumiodvs2 volumio[860]: info: [1749729289570] CoreMusicLibrary::Adding element Webradio Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Initializing BBC Radios Jun 12 13:54:49 volumiodvs2 sudo[1076]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 12 13:54:49 volumiodvs2 sudo[1076]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:49 volumiodvs2 sudo[1076]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jun 12 13:54:49 volumiodvs2 sudo[1076]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Creating Spotify config file Jun 12 13:54:49 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Loading i18n strings for locale it Jun 12 13:54:49 volumiodvs2 volumio[860]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Jun 12 13:54:49 volumiodvs2 volumio[860]: info: Volumio Calling Home Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Discovery: adding 4af90c75-ec46-4380-be9e-276b855bb976 Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Discovery: Found device VolumioDVS2 Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioGetState Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:50 volumiodvs2 volumio[860]: info: MPD Permissions set Jun 12 13:54:50 volumiodvs2 volumio[860]: info: MPD Permissions set Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Volumio called home Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Spotify config file written Jun 12 13:54:50 volumiodvs2 volumio[860]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 sudo[1119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 12 13:54:50 volumiodvs2 sudo[1119]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 12 13:54:50 volumiodvs2 volumio[860]: info: No need to fix Spotify hosts Jun 12 13:54:50 volumiodvs2 volumio[860]: info: VolumeController:: Volume=100 Mute =false Jun 12 13:54:50 volumiodvs2 systemd[1]: Started go-librespot Daemon. Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreStateMachine::pushState Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioPushState Jun 12 13:54:50 volumiodvs2 go-librespot[1129]: go-librespot daemon starting... Jun 12 13:54:50 volumiodvs2 sudo[1119]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Starting Shairport Sync Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Starting Shairport Sync Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Starting Shairport Sync Jun 12 13:54:50 volumiodvs2 sudo[1132]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 12 13:54:50 volumiodvs2 sudo[1132]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:50 volumiodvs2 sudo[1134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 12 13:54:50 volumiodvs2 sudo[1134]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:50 volumiodvs2 sudo[1137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 12 13:54:50 volumiodvs2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 12 13:54:50 volumiodvs2 systemd[1]: shairport-sync.service: Succeeded. Jun 12 13:54:50 volumiodvs2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 12 13:54:50 volumiodvs2 sudo[1137]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioGetState Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:50 volumiodvs2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 12 13:54:50 volumiodvs2 sudo[1132]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:50 volumiodvs2 sudo[1134]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Shairport-Sync Started Jun 12 13:54:50 volumiodvs2 volumio[860]: Error adding Membership: Error: addMembership EINVAL Jun 12 13:54:50 volumiodvs2 sudo[1137]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Shairport-Sync Started Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Shairport-Sync Started Jun 12 13:54:50 volumiodvs2 volumio[860]: verbose: New Socket.io Connection to 192.168.1.151 from 192.168.1.94 UA: Mozilla/5.0 (Linux x86_64) AppleWebKit/610.1 (KHTML, like Gecko) JavaFX/8.0 Safari/610.1 Engine version: 3 Transport: polling Total Clients: 8 Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioGetVisibleSources Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioGetState Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Received Get System Info Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Discovery: Getting this device information Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioGetState Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioGetState Jun 12 13:54:50 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:50 volumiodvs2 volumio[860]: info: Listing playlists Jun 12 13:54:51 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:54:51+02:00" level=info msg="running go-librespot 0.2.0" Jun 12 13:54:51 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:54:51+02:00" level=debug msg="app state loaded" Jun 12 13:54:51 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:54:51+02:00" level=debug msg="stored credentials not found" Jun 12 13:54:51 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:54:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 12 13:54:51 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:54:51+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 12 13:54:51 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:54:51+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 12 13:54:51 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:54:51+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]" Jun 12 13:54:51 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:54:51+02:00" level=info msg="zeroconf server listening on port 32967" Jun 12 13:54:51 volumiodvs2 volumio[860]: info: minidlna: Found miniDLNA version 1.2.1 Jun 12 13:54:51 volumiodvs2 volumio[860]: info: minidlna: Starting minidlna.service Jun 12 13:54:51 volumiodvs2 volumio-remote-updater[637]: [2025-06-12 13:54:51] [connect] Successful connection Jun 12 13:54:51 volumiodvs2 sudo[1151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service Jun 12 13:54:51 volumiodvs2 sudo[1151]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:51 volumiodvs2 volumio-remote-updater[637]: [2025-06-12 13:54:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1749729291 101 Jun 12 13:54:51 volumiodvs2 volumio[860]: 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: 9 Jun 12 13:54:51 volumiodvs2 systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. Jun 12 13:54:51 volumiodvs2 sudo[1151]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:51 volumiodvs2 volumio[860]: info: minidlna: systemctl start minidlna.service succeeded. Jun 12 13:54:53 volumiodvs2 mpd[1099]: Jun 12 13:54 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 12 13:54:53 volumiodvs2 volumio[860]: info: go-librespot daemon successfully initialized Jun 12 13:54:53 volumiodvs2 systemd[1]: Started Music Player Daemon. Jun 12 13:54:53 volumiodvs2 sudo[1055]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:53 volumiodvs2 sudo[1064]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:53 volumiodvs2 volumio[860]: info: Completed starting Core Plugins Jun 12 13:54:53 volumiodvs2 volumio[860]: info: ------------------------------------------- Jun 12 13:54:53 volumiodvs2 volumio[860]: info: ----- MyVolumio plugins startup ---- Jun 12 13:54:53 volumiodvs2 volumio[860]: info: ------------------------------------------- Jun 12 13:54:53 volumiodvs2 volumio[860]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 12 13:54:53 volumiodvs2 volumio[860]: error: MPD error: The expression evaluated to a falsy value: Jun 12 13:54:53 volumiodvs2 volumio[860]: assert.ok(self.idling) Jun 12 13:54:53 volumiodvs2 volumio[860]: error: The expression evaluated to a falsy value: Jun 12 13:54:53 volumiodvs2 volumio[860]: assert.ok(self.idling) Jun 12 13:54:53 volumiodvs2 volumio[860]: info: MPD running with PID1099 Jun 12 13:54:53 volumiodvs2 volumio[860]: ,establishing connection Jun 12 13:54:53 volumiodvs2 sudo[1164]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 12 13:54:53 volumiodvs2 sudo[1164]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:53 volumiodvs2 volumio[860]: error: MPD error: The expression evaluated to a falsy value: Jun 12 13:54:53 volumiodvs2 volumio[860]: assert.ok(self.idling) Jun 12 13:54:53 volumiodvs2 volumio[860]: error: The expression evaluated to a falsy value: Jun 12 13:54:53 volumiodvs2 volumio[860]: assert.ok(self.idling) Jun 12 13:54:53 volumiodvs2 sudo[1164]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:53 volumiodvs2 volumio[860]: error: updateQueue error: null Jun 12 13:54:53 volumiodvs2 sudo[1166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 12 13:54:53 volumiodvs2 sudo[1166]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:53 volumiodvs2 sudo[1166]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:53 volumiodvs2 sudo[1170]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 12 13:54:53 volumiodvs2 sudo[1170]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:54:53 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioGetState Jun 12 13:54:53 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:54:53 volumiodvs2 systemd[1]: Started UPnP Renderer front-end to MPD. Jun 12 13:54:53 volumiodvs2 sudo[1170]: pam_unix(sudo:session): session closed for user root Jun 12 13:54:53 volumiodvs2 volumio[860]: info: Upmpdcli Daemon Started Jun 12 13:54:53 volumiodvs2 volumio[1172]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 12 13:54:56 volumiodvs2 volumio[860]: info: Initializing connection to go-librespot Websocket Jun 12 13:54:56 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:54:56+02:00" level=debug msg="new websocket client" Jun 12 13:54:56 volumiodvs2 volumio[860]: info: Connection to go-librespot Websocket established Jun 12 13:54:59 volumiodvs2 volumio[860]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 12 13:54:59 volumiodvs2 systemd[1]: systemd-fsckd.service: Succeeded. Jun 12 13:55:00 volumiodvs2 volumio[860]: info: Getting Spotify volume Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="obtained new client token: AABrMoayX+mhcB2I/I+QbOd15AQND1/5vQ8t/YFRZWX56X7waN5iIag3Q7jLPfnMf4Nmk8w0Z9JrX40NAUPNzf7h5tQuuPYoKal0ZxNmojA6Kj03ARW5TUj54kq+qQhvOpzpac8GM9YsBn0f6sOgtbUs3K9UI/8jL9SlharEFt9D863TODvsU3ZH84sdwAIZfedZp3HiYbM/Ooc/9Vv08tKBnUOnPxHlTvoOOeb6YgxHtIt7Jv3K4MRieg==" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="completed keyexchange" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="completed challenge" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=info msg="authenticated AP as 31bhkfrqcmbfquxmm7rhzpay7bni" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=info msg="authenticated Login5 as 31bhkfrqcmbfquxmm7rhzpay7bni" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=info msg="accepted zeroconf user 31bhkfrqcmbfquxmm7rhzpay7bni from YOGA7840HS" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="dealer connection opened" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=trace msg="starting accesspoint recv loop" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=trace msg="received accesspoint ping" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=trace msg="starting dealer recv loop" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="received connection id: ZjgyMjE5MjgtNmE4Yy00YTE5LWEzYzktYmMwNTg0OWQ3NzNiK2RlYWxlcit0Y3A6Ly8wYWNhNWE2MC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNUZDMUZCQzA5OEEyNjdDRUI5NjRGODhCODEwMzMyMEIwRkYwQkVBRDc1QTRERUQ2MTdEM0M4MTI3QThFMUU4Qw==" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=trace msg="received accesspoint pong ack" Jun 12 13:55:02 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:02+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="handling transfer player command from bd07dc259e388eea8ae4aa2d18f6b7757a537ebc" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:4th1doMlQifn82f0ol5AHw" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=trace msg="fetched new page 0 with 22 items (list: 22)" uri="spotify:playlist:4th1doMlQifn82f0ol5AHw" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="loading track (paused: false, position: 118339ms)" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=trace msg="emitting websocket event: will_play" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="selected format OGG_VORBIS_320 (6287c3ca07a2357f8ca997b1e151738610e4dc51)" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="requested aes key for file 6287c3ca07a2357f8ca997b1e151738610e4dc51, gid: 68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1366" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="fetched first chunk of 17, total size is 8728332 bytes" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1129" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:03 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:03+02:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="fetched chunk 11/16, size: 524288" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="fetched chunk 8/16, size: 524288" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=trace msg="seek to 118339ms (diff: 154ms, samples: 5218749, bytes: 4280622)" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="created new output device" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="fetched chunk 10/16, size: 524288" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="fetched chunk 9/16, size: 524288" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:04 volumiodvs2 kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=info msg="loaded track \"Yeha Noha (Wishes Of Happiness And Prosperity)\" (paused: false, position: 118339ms, duration: 243666ms, prefetched: false)" uri="spotify:track:68sgDMBVvhk62UsCqqpO8W" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=trace msg="scheduling prefetch in 95s" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=trace msg="emitting websocket event: metadata" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=trace msg="emitting websocket event: active" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="sending successful reply for dealer request" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 12 13:55:04 volumiodvs2 go-librespot[1129]: time="2025-06-12T13:55:04+02:00" level=trace msg="emitting websocket event: playing" Jun 12 13:55:04 volumiodvs2 volumio[860]: info: Spotify volume: 100 Jun 12 13:55:04 volumiodvs2 volumio[860]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:68sgDMBVvhk62UsCqqpO8W","play_origin":"com.spotify.gaia"}} Jun 12 13:55:04 volumiodvs2 volumio[860]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:68sgDMBVvhk62UsCqqpO8W","name":"Yeha Noha (Wishes Of Happiness And Prosperity)","artist_names":["Sacred Spirit"],"album_name":"Chants And Dances Of The Native Americans","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0215f002c2619e678c1cb2e95e","position":118339,"duration":243666,"release_date":"year:2011 month:1 day:1","track_number":7,"disc_number":1}} Jun 12 13:55:04 volumiodvs2 volumio[860]: SPOTIFY: received: {"type":"active","data":null} Jun 12 13:55:04 volumiodvs2 volumio[860]: info: Aligning Spotify Volume to Volumio Volume Jun 12 13:55:04 volumiodvs2 volumio[860]: info: CoreCommandRouter::volumioGetState Jun 12 13:55:04 volumiodvs2 volumio[860]: info: CorePlayQueue::getTrack 0 Jun 12 13:55:04 volumiodvs2 volumio[860]: info: Setting Spotify Volume from Volumio: 100 Jun 12 13:55:04 volumiodvs2 volumio[860]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:68sgDMBVvhk62UsCqqpO8W","play_origin":"com.spotify.gaia"}} Jun 12 13:55:04 volumiodvs2 volumio[860]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 12 13:55:04 volumiodvs2 volumio[860]: TypeError: Cannot read property 'service' of undefined Jun 12 13:55:04 volumiodvs2 volumio[860]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:340:50) Jun 12 13:55:04 volumiodvs2 volumio[860]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:266:18) Jun 12 13:55:04 volumiodvs2 volumio[860]: at WebSocket.message (/data/plugins/music_service/spop/index.js:193:14) Jun 12 13:55:04 volumiodvs2 volumio[860]: at WebSocket.emit (events.js:315:20) Jun 12 13:55:04 volumiodvs2 volumio[860]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jun 12 13:55:04 volumiodvs2 volumio[860]: at Receiver.emit (events.js:315:20) Jun 12 13:55:04 volumiodvs2 volumio[860]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jun 12 13:55:04 volumiodvs2 volumio[860]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jun 12 13:55:04 volumiodvs2 volumio[860]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jun 12 13:55:04 volumiodvs2 volumio[860]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jun 12 13:55:04 volumiodvs2 volumio[860]: at writeOrBuffer (internal/streams/writable.js:358:12) Jun 12 13:55:04 volumiodvs2 volumio[860]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jun 12 13:55:04 volumiodvs2 volumio[860]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jun 12 13:55:04 volumiodvs2 volumio[860]: at Socket.emit (events.js:315:20) Jun 12 13:55:04 volumiodvs2 volumio[860]: at addChunk (internal/streams/readable.js:309:12) Jun 12 13:55:04 volumiodvs2 volumio[860]: at readableAddChunk (internal/streams/readable.js:284:9) Jun 12 13:55:04 volumiodvs2 volumio[860]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 12 13:55:05 volumiodvs2 sudo[1212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-12 13:54 Jun 12 13:55:05 volumiodvs2 sudo[1212]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 12 13:55:05 volumiodvs2 systemd[1]: systemd-hostnamed.service: Succeeded. PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"