-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sat 2025-12-13 09:36:11 CET. -- Dec 13 09:35:09 xs-4000 kernel: pcieport 0000:00:00.0: enabling device (0000 -> 0002) Dec 13 09:35:09 xs-4000 kernel: pcieport 0000:00:00.0: PME: Signaling with IRQ 45 Dec 13 09:35:09 xs-4000 kernel: bcm2708_fb soc:fb: FB found 1 display(s) Dec 13 09:35:09 xs-4000 kernel: Console: switching to colour frame buffer device 80x30 Dec 13 09:35:09 xs-4000 kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Dec 13 09:35:09 xs-4000 kernel: iproc-rng200 fe104000.rng: hwrng registered Dec 13 09:35:09 xs-4000 kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Dec 13 09:35:09 xs-4000 kernel: brd: module loaded Dec 13 09:35:09 xs-4000 kernel: loop: module loaded Dec 13 09:35:09 xs-4000 kernel: Loading iSCSI transport class v2.0-870. Dec 13 09:35:09 xs-4000 kernel: bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 Dec 13 09:35:09 xs-4000 kernel: Freeing initrd memory: 28132K Dec 13 09:35:09 xs-4000 kernel: unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus Dec 13 09:35:09 xs-4000 kernel: usbcore: registered new device driver r8152-cfgselector Dec 13 09:35:09 xs-4000 kernel: usbcore: registered new interface driver r8152 Dec 13 09:35:09 xs-4000 kernel: usbcore: registered new interface driver lan78xx Dec 13 09:35:09 xs-4000 kernel: usbcore: registered new interface driver smsc95xx Dec 13 09:35:09 xs-4000 kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Dec 13 09:35:09 xs-4000 kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 Dec 13 09:35:09 xs-4000 kernel: xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0700240000000890 Dec 13 09:35:09 xs-4000 kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Dec 13 09:35:09 xs-4000 kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Dec 13 09:35:09 xs-4000 kernel: xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Dec 13 09:35:09 xs-4000 kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06 Dec 13 09:35:09 xs-4000 kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Dec 13 09:35:09 xs-4000 kernel: usb usb1: Product: xHCI Host Controller Dec 13 09:35:09 xs-4000 kernel: usb usb1: Manufacturer: Linux 6.6.62-v7l+ xhci-hcd Dec 13 09:35:09 xs-4000 kernel: usb usb1: SerialNumber: 0000:01:00.0 Dec 13 09:35:09 xs-4000 kernel: hub 1-0:1.0: USB hub found Dec 13 09:35:09 xs-4000 kernel: hub 1-0:1.0: 1 port detected Dec 13 09:35:09 xs-4000 kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.06 Dec 13 09:35:09 xs-4000 kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Dec 13 09:35:09 xs-4000 kernel: usb usb2: Product: xHCI Host Controller Dec 13 09:35:09 xs-4000 kernel: usb usb2: Manufacturer: Linux 6.6.62-v7l+ xhci-hcd Dec 13 09:35:09 xs-4000 kernel: usb usb2: SerialNumber: 0000:01:00.0 Dec 13 09:35:09 xs-4000 kernel: hub 2-0:1.0: USB hub found Dec 13 09:35:09 xs-4000 kernel: hub 2-0:1.0: 4 ports detected Dec 13 09:35:09 xs-4000 kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Dec 13 09:35:09 xs-4000 kernel: dwc_otg: FIQ enabled Dec 13 09:35:09 xs-4000 kernel: dwc_otg: NAK holdoff enabled Dec 13 09:35:09 xs-4000 kernel: dwc_otg: FIQ split-transaction FSM enabled Dec 13 09:35:09 xs-4000 kernel: Module dwc_common_port init Dec 13 09:35:09 xs-4000 kernel: usbcore: registered new interface driver uas Dec 13 09:35:09 xs-4000 kernel: usbcore: registered new interface driver usb-storage Dec 13 09:35:09 xs-4000 kernel: mousedev: PS/2 mouse device common for all mice Dec 13 09:35:09 xs-4000 kernel: sdhci: Secure Digital Host Controller Interface driver Dec 13 09:35:09 xs-4000 kernel: sdhci: Copyright(c) Pierre Ossman Dec 13 09:35:09 xs-4000 kernel: sdhci-pltfm: SDHCI platform and OF driver helper Dec 13 09:35:09 xs-4000 kernel: ledtrig-cpu: registered to indicate activity on CPUs Dec 13 09:35:09 xs-4000 kernel: hid: raw HID events driver (C) Jiri Kosina Dec 13 09:35:09 xs-4000 kernel: usbcore: registered new interface driver usbhid Dec 13 09:35:09 xs-4000 kernel: usbhid: USB HID core driver Dec 13 09:35:09 xs-4000 kernel: Initializing XFRM netlink socket Dec 13 09:35:09 xs-4000 kernel: NET: Registered PF_PACKET protocol family Dec 13 09:35:09 xs-4000 kernel: Key type dns_resolver registered Dec 13 09:35:09 xs-4000 kernel: Registering SWP/SWPB emulation handler Dec 13 09:35:09 xs-4000 kernel: registered taskstats version 1 Dec 13 09:35:09 xs-4000 kernel: Loading compiled-in X.509 certificates Dec 13 09:35:09 xs-4000 kernel: Key type .fscrypt registered Dec 13 09:35:09 xs-4000 kernel: Key type fscrypt-provisioning registered Dec 13 09:35:09 xs-4000 kernel: uart-pl011 fe201000.serial: there is not valid maps for state default Dec 13 09:35:09 xs-4000 kernel: uart-pl011 fe201000.serial: cts_event_workaround enabled Dec 13 09:35:09 xs-4000 kernel: fe201000.serial: ttyAMA1 at MMIO 0xfe201000 (irq = 51, base_baud = 0) is a PL011 rev2 Dec 13 09:35:09 xs-4000 kernel: serial serial0: tty port ttyAMA1 registered Dec 13 09:35:09 xs-4000 kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Dec 13 09:35:09 xs-4000 kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Dec 13 09:35:09 xs-4000 kernel: mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 Dec 13 09:35:09 xs-4000 kernel: mmc-bcm2835 fe300000.mmcnr: DMA channel allocated Dec 13 09:35:09 xs-4000 kernel: of_cfs_init Dec 13 09:35:09 xs-4000 kernel: of_cfs_init: OK Dec 13 09:35:09 xs-4000 kernel: clk: Disabling unused clocks Dec 13 09:35:09 xs-4000 kernel: mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA Dec 13 09:35:09 xs-4000 kernel: Freeing unused kernel image (initmem) memory: 2048K Dec 13 09:35:09 xs-4000 kernel: Run /init as init process Dec 13 09:35:09 xs-4000 kernel: with arguments: Dec 13 09:35:09 xs-4000 kernel: /init Dec 13 09:35:09 xs-4000 kernel: splash Dec 13 09:35:09 xs-4000 kernel: nodebug Dec 13 09:35:09 xs-4000 kernel: with environment: Dec 13 09:35:09 xs-4000 kernel: HOME=/ Dec 13 09:35:09 xs-4000 kernel: TERM=linux Dec 13 09:35:09 xs-4000 kernel: numa_policy=interleave Dec 13 09:35:09 xs-4000 kernel: imgpart=UUID=9b6a8fd4-d1e0-41c3-90e3-655c7141a81c Dec 13 09:35:09 xs-4000 kernel: imgfile=/volumio_current.sqsh Dec 13 09:35:09 xs-4000 kernel: bootpart=UUID=7883-9333 Dec 13 09:35:09 xs-4000 kernel: datapart=UUID=f0f21e6a-0d4c-4d61-b970-25cec5bd08b3 Dec 13 09:35:09 xs-4000 kernel: uuidconfig=cmdline.txt Dec 13 09:35:09 xs-4000 kernel: pcie_aspm=off Dec 13 09:35:09 xs-4000 kernel: bootdelay=7 Dec 13 09:35:09 xs-4000 kernel: use_kmsg=no Dec 13 09:35:09 xs-4000 kernel: mmc1: new high speed SDIO card at address 0001 Dec 13 09:35:09 xs-4000 kernel: mmc0: new ultra high speed DDR50 SDXC card at address 5048 Dec 13 09:35:09 xs-4000 kernel: mmcblk0: mmc0:5048 SD64G 58.0 GiB Dec 13 09:35:09 xs-4000 kernel: mmcblk0: p1 p2 p3 Dec 13 09:35:09 xs-4000 kernel: mmcblk0: mmc0:5048 SD64G 58.0 GiB (quirks 0x00008000) Dec 13 09:35:09 xs-4000 kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd Dec 13 09:35:09 xs-4000 kernel: usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 Dec 13 09:35:09 xs-4000 kernel: usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Dec 13 09:35:09 xs-4000 kernel: usb 1-1: Product: USB2.0 Hub Dec 13 09:35:09 xs-4000 kernel: hub 1-1:1.0: USB hub found Dec 13 09:35:09 xs-4000 kernel: hub 1-1:1.0: 4 ports detected Dec 13 09:35:09 xs-4000 kernel: fuse: init (API version 7.39) Dec 13 09:35:09 xs-4000 kernel: usb 1-1.2: new high-speed USB device number 3 using xhci_hcd Dec 13 09:35:09 xs-4000 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Dec 13 09:35:09 xs-4000 kernel: usb 1-1.2: New USB device found, idVendor=20b1, idProduct=3091, bcdDevice= 7.06 Dec 13 09:35:09 xs-4000 kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=3, SerialNumber=0 Dec 13 09:35:09 xs-4000 kernel: usb 1-1.2: Product: nubert xCore USB Audio Dec 13 09:35:09 xs-4000 kernel: usb 1-1.2: Manufacturer: nubert Dec 13 09:35:09 xs-4000 kernel: EXT4-fs (mmcblk0p2): recovery complete Dec 13 09:35:09 xs-4000 kernel: EXT4-fs (mmcblk0p2): mounted filesystem 9b6a8fd4-d1e0-41c3-90e3-655c7141a81c r/w with ordered data mode. Quota mode: none. Dec 13 09:35:09 xs-4000 kernel: loop0: detected capacity change from 0 to 1004368 Dec 13 09:35:09 xs-4000 kernel: EXT4-fs (mmcblk0p3): recovery complete Dec 13 09:35:09 xs-4000 kernel: EXT4-fs (mmcblk0p3): mounted filesystem f0f21e6a-0d4c-4d61-b970-25cec5bd08b3 r/w with ordered data mode. Quota mode: none. Dec 13 09:35:09 xs-4000 systemd[1]: System time before build time, advancing clock. Dec 13 09:35:09 xs-4000 kernel: NET: Registered PF_INET6 protocol family Dec 13 09:35:09 xs-4000 kernel: Segment Routing with IPv6 Dec 13 09:35:09 xs-4000 kernel: In-situ OAM (IOAM) with IPv6 Dec 13 09:35:09 xs-4000 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) Dec 13 09:35:09 xs-4000 systemd[1]: Detected architecture arm. Dec 13 09:35:09 xs-4000 systemd[1]: Set hostname to . Dec 13 09:35:09 xs-4000 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. Dec 13 09:35:09 xs-4000 systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. Dec 13 09:35:09 xs-4000 systemd[1]: Listening on initctl Compatibility Named Pipe. Dec 13 09:35:09 xs-4000 systemd[1]: Listening on Journal Socket (/dev/log). Dec 13 09:35:09 xs-4000 systemd[1]: Reached target System Time Synchronized. Dec 13 09:35:09 xs-4000 systemd[1]: Listening on Journal Audit Socket. Dec 13 09:35:09 xs-4000 systemd[1]: Listening on Journal Socket. Dec 13 09:35:09 xs-4000 kernel: i2c_dev: i2c /dev entries driver Dec 13 09:35:09 xs-4000 systemd-journald[309]: Journal started Dec 13 09:35:09 xs-4000 systemd-journald[309]: Runtime journal (/run/log/journal/a4d620ccb4a6a12010c39c5d649876fe) is 7.5M, max 30.0M, 22.5M free. Dec 13 09:35:09 xs-4000 systemd-modules-load[297]: Inserted module 'i2c_dev' Dec 13 09:35:09 xs-4000 fake-hwclock[304]: Sat Dec 13 08:35:09 UTC 2025 Dec 13 09:35:09 xs-4000 systemd[1]: Started Load/Save Random Seed. Dec 13 09:35:09 xs-4000 systemd[1]: dynamicswap.service: Succeeded. Dec 13 09:35:09 xs-4000 systemd[1]: Started Create System Users. Dec 13 09:35:09 xs-4000 systemd[1]: Starting Create Static Device Nodes in /dev... Dec 13 09:35:09 xs-4000 systemd[1]: Started Create Static Device Nodes in /dev. Dec 13 09:35:09 xs-4000 systemd[1]: Reached target Local File Systems (Pre). Dec 13 09:35:09 xs-4000 systemd[1]: Mounting /var/spool/cups... Dec 13 09:35:09 xs-4000 systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Dec 13 09:35:09 xs-4000 systemd[1]: Mounting /tmp... Dec 13 09:35:09 xs-4000 systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Dec 13 09:35:09 xs-4000 systemd[1]: Mounting /var/log... Dec 13 09:35:09 xs-4000 systemd[1]: Starting udev Kernel Device Manager... Dec 13 09:35:09 xs-4000 systemd[1]: Started udev Coldplug all Devices. Dec 13 09:35:09 xs-4000 systemd[1]: Mounted /var/spool/cups. Dec 13 09:35:09 xs-4000 systemd[1]: Mounted /tmp. Dec 13 09:35:09 xs-4000 systemd[1]: Mounted /var/log. Dec 13 09:35:09 xs-4000 systemd[1]: Starting Flush Journal to Persistent Storage... Dec 13 09:35:09 xs-4000 systemd[1]: Mounting /var/spool/cups/tmp... Dec 13 09:35:09 xs-4000 systemd[1]: Starting Helper to synchronize boot up for ifupdown... Dec 13 09:35:09 xs-4000 systemd[1]: Mounted /var/spool/cups/tmp. Dec 13 09:35:09 xs-4000 systemd-udevd[333]: Network interface NamePolicy= disabled on kernel command line, ignoring. Dec 13 09:35:09 xs-4000 systemd-journald[309]: Runtime journal (/run/log/journal/a4d620ccb4a6a12010c39c5d649876fe) is 7.5M, max 30.0M, 22.5M free. Dec 13 09:35:09 xs-4000 systemd[1]: Started Helper to synchronize boot up for ifupdown. Dec 13 09:35:09 xs-4000 systemd[1]: Started udev Kernel Device Manager. Dec 13 09:35:09 xs-4000 systemd[1]: Starting Show Plymouth Boot Screen... Dec 13 09:35:09 xs-4000 systemd[1]: Started Flush Journal to Persistent Storage. Dec 13 09:35:09 xs-4000 systemd[1]: plymouth-start.service: Succeeded. Dec 13 09:35:09 xs-4000 systemd[1]: Started Show Plymouth Boot Screen. Dec 13 09:35:09 xs-4000 systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Dec 13 09:35:09 xs-4000 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Dec 13 09:35:09 xs-4000 systemd[1]: Reached target Paths. Dec 13 09:35:09 xs-4000 systemd[1]: Reached target Local Encrypted Volumes. Dec 13 09:35:09 xs-4000 systemd-udevd[339]: Using default interface naming scheme 'v240'. Dec 13 09:35:09 xs-4000 kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Dec 13 09:35:09 xs-4000 kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Dec 13 09:35:09 xs-4000 kernel: [vc_sm_connected_init]: start Dec 13 09:35:09 xs-4000 kernel: [vc_sm_connected_init]: installed successfully Dec 13 09:35:09 xs-4000 systemd-udevd[339]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Dec 13 09:35:09 xs-4000 kernel: mc: Linux media interface: v0.10 Dec 13 09:35:09 xs-4000 kernel: rpi-gpiomem fe200000.gpiomem: window base 0xfe200000 size 0x00001000 Dec 13 09:35:09 xs-4000 kernel: rpi-gpiomem fe200000.gpiomem: initialised 1 regions as /dev/gpiomem Dec 13 09:35:09 xs-4000 kernel: videodev: Linux video capture interface: v2.00 Dec 13 09:35:09 xs-4000 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Dec 13 09:35:09 xs-4000 kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Dec 13 09:35:09 xs-4000 kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Dec 13 09:35:09 xs-4000 kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Dec 13 09:35:09 xs-4000 kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. Dec 13 09:35:09 xs-4000 kernel: rpivid feb10000.codec: Device registered as /dev/video19 Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Dec 13 09:35:09 xs-4000 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Dec 13 09:35:09 xs-4000 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Dec 13 09:35:09 xs-4000 kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Dec 13 09:35:09 xs-4000 kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Dec 13 09:35:09 xs-4000 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Dec 13 09:35:09 xs-4000 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Dec 13 09:35:09 xs-4000 kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Dec 13 09:35:09 xs-4000 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Dec 13 09:35:09 xs-4000 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Dec 13 09:35:09 xs-4000 kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Dec 13 09:35:09 xs-4000 kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Dec 13 09:35:09 xs-4000 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Dec 13 09:35:09 xs-4000 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Dec 13 09:35:09 xs-4000 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Dec 13 09:35:09 xs-4000 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Dec 13 09:35:09 xs-4000 systemd[1]: Found device /dev/disk/by-uuid/7883-9333. Dec 13 09:35:09 xs-4000 kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Dec 13 09:35:09 xs-4000 kernel: Bluetooth: Core ver 2.22 Dec 13 09:35:09 xs-4000 kernel: NET: Registered PF_BLUETOOTH protocol family Dec 13 09:35:09 xs-4000 kernel: Bluetooth: HCI device and connection manager initialized Dec 13 09:35:09 xs-4000 kernel: Bluetooth: HCI socket layer initialized Dec 13 09:35:09 xs-4000 kernel: Bluetooth: L2CAP socket layer initialized Dec 13 09:35:09 xs-4000 kernel: Bluetooth: SCO socket layer initialized Dec 13 09:35:09 xs-4000 kernel: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Dec 13 09:35:09 xs-4000 kernel: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Dec 13 09:35:09 xs-4000 kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Dec 13 09:35:09 xs-4000 kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Dec 13 09:35:09 xs-4000 systemd[1]: Starting File System Check on /dev/disk/by-uuid/7883-9333... Dec 13 09:35:09 xs-4000 kernel: Bluetooth: HCI UART driver ver 2.3 Dec 13 09:35:09 xs-4000 kernel: Bluetooth: HCI UART protocol H4 registered Dec 13 09:35:09 xs-4000 kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Dec 13 09:35:09 xs-4000 kernel: Bluetooth: HCI UART protocol Broadcom registered Dec 13 09:35:09 xs-4000 kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Dec 13 09:35:10 xs-4000 kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Dec 13 09:35:10 xs-4000 kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Dec 13 09:35:10 xs-4000 kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Dec 13 09:35:10 xs-4000 kernel: usbcore: registered new interface driver brcmfmac Dec 13 09:35:10 xs-4000 kernel: usbcore: registered new interface driver snd-usb-audio Dec 13 09:35:10 xs-4000 kernel: uart-pl011 fe201000.serial: no DMA platform data Dec 13 09:35:10 xs-4000 systemd-fsck[416]: fsck.fat 4.1 (2017-01-24) Dec 13 09:35:10 xs-4000 systemd-fsck[416]: /dev/mmcblk0p1: 409 files, 41773/46774 clusters Dec 13 09:35:09 xs-4000 systemd-udevd[344]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Dec 13 09:35:10 xs-4000 systemd[1]: Started File System Check on /dev/disk/by-uuid/7883-9333. Dec 13 09:35:10 xs-4000 kernel: brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob available (err=-2) Dec 13 09:35:10 xs-4000 kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 Dec 13 09:35:10 xs-4000 kernel: Bluetooth: hci0: BCM: chip id 107 Dec 13 09:35:10 xs-4000 kernel: Bluetooth: hci0: BCM: features 0x2f Dec 13 09:35:10 xs-4000 kernel: Bluetooth: hci0: BCM4345C0 Dec 13 09:35:10 xs-4000 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Dec 13 09:35:10 xs-4000 kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Dec 13 09:35:10 xs-4000 systemd-udevd[349]: Using default interface naming scheme 'v240'. Dec 13 09:35:10 xs-4000 systemd-udevd[349]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Dec 13 09:35:10 xs-4000 kernel: alsactl[464]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set Dec 13 09:35:10 xs-4000 systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Dec 13 09:35:10 xs-4000 systemd-udevd[351]: Process '/bin/bash -c '/usr/local/bin/volumio usbattach'' failed with exit code 7. Dec 13 09:35:10 xs-4000 systemd[1]: Condition check resulted in /sys/subsystem/net/devices/wlan0 being skipped. Dec 13 09:35:10 xs-4000 systemd[1]: Created slice system-bthelper.slice. Dec 13 09:35:10 xs-4000 systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Dec 13 09:35:10 xs-4000 systemd[1]: Condition check resulted in Huge Pages File System being skipped. Dec 13 09:35:10 xs-4000 systemd[1]: Starting Show Plymouth Boot Screen... Dec 13 09:35:10 xs-4000 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Dec 13 09:35:10 xs-4000 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Dec 13 09:35:10 xs-4000 systemd[1]: Mounting /boot... Dec 13 09:35:10 xs-4000 systemd[1]: Started File System Check Daemon to report status. Dec 13 09:35:10 xs-4000 systemd[1]: Starting Load/Save RF Kill Switch Status... Dec 13 09:35:10 xs-4000 systemd[1]: plymouth-start.service: Succeeded. Dec 13 09:35:10 xs-4000 systemd[1]: Started Show Plymouth Boot Screen. Dec 13 09:35:10 xs-4000 systemd[1]: Mounted /boot. Dec 13 09:35:10 xs-4000 systemd[1]: Reached target Local File Systems. Dec 13 09:35:10 xs-4000 systemd[1]: Starting Raise network interfaces... Dec 13 09:35:10 xs-4000 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Dec 13 09:35:10 xs-4000 systemd[1]: Starting Preprocess NFS configuration... Dec 13 09:35:10 xs-4000 systemd[1]: Started ifup for wlan0. Dec 13 09:35:10 xs-4000 systemd[1]: Started ifup for eth0. Dec 13 09:35:10 xs-4000 systemd[1]: Starting Create Volatile Files and Directories... Dec 13 09:35:10 xs-4000 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Dec 13 09:35:10 xs-4000 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Dec 13 09:35:10 xs-4000 systemd[1]: Started Load/Save RF Kill Switch Status. Dec 13 09:35:10 xs-4000 systemd[1]: Received SIGRTMIN+20 from PID 196 (plymouthd). Dec 13 09:35:10 xs-4000 systemd[1]: plymouth-read-write.service: Succeeded. Dec 13 09:35:10 xs-4000 systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Dec 13 09:35:10 xs-4000 systemd[1]: nfs-config.service: Succeeded. Dec 13 09:35:10 xs-4000 systemd[1]: Started Preprocess NFS configuration. Dec 13 09:35:10 xs-4000 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Dec 13 09:35:10 xs-4000 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Dec 13 09:35:10 xs-4000 systemd[1]: Reached target NFS client services. Dec 13 09:35:10 xs-4000 kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211 Dec 13 09:35:10 xs-4000 systemd[1]: Started Create Volatile Files and Directories. Dec 13 09:35:10 xs-4000 systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Dec 13 09:35:11 xs-4000 systemd[1]: Starting RPC bind portmap service... Dec 13 09:35:11 xs-4000 systemd[1]: Starting Update UTMP about System Boot/Shutdown... Dec 13 09:35:11 xs-4000 systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Dec 13 09:35:11 xs-4000 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 13 09:35:11 xs-4000 kernel: Bluetooth: hci0: BCM: features 0x2f Dec 13 09:35:11 xs-4000 kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Dec 13 09:35:11 xs-4000 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Dec 13 09:35:11 xs-4000 systemd[1]: Started Update UTMP about System Boot/Shutdown. Dec 13 09:35:11 xs-4000 systemd[1]: Reached target System Initialization. Dec 13 09:35:11 xs-4000 kernel: 8021q: 802.1Q VLAN Support v1.8 Dec 13 09:35:11 xs-4000 systemd[1]: Listening on D-Bus System Message Bus Socket. Dec 13 09:35:11 xs-4000 systemd[1]: Started Daily apt download activities. Dec 13 09:35:11 xs-4000 systemd[1]: Started Daily apt upgrade and clean activities. Dec 13 09:35:11 xs-4000 systemd[1]: Started Daily Cleanup of Temporary Directories. Dec 13 09:35:11 xs-4000 systemd[1]: Reached target Timers. Dec 13 09:35:11 xs-4000 systemd[1]: Listening on triggerhappy.socket. Dec 13 09:35:11 xs-4000 systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Dec 13 09:35:11 xs-4000 systemd[1]: Reached target Sockets. Dec 13 09:35:11 xs-4000 systemd[1]: Reached target Basic System. Dec 13 09:35:11 xs-4000 systemd[1]: Starting Volumio Time Update Utility... Dec 13 09:35:11 xs-4000 systemd[1]: Starting Configure Bluetooth Modems connected by UART... Dec 13 09:35:11 xs-4000 systemd[1]: Started volumio-remote-updater.service. Dec 13 09:35:11 xs-4000 volumio-time-update[568]: volumio-time-update-util: Fetching time from Volumio... Dec 13 09:35:11 xs-4000 systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Dec 13 09:35:11 xs-4000 systemd[1]: Started UPnP Renderer front-end to MPD. Dec 13 09:35:11 xs-4000 systemd[1]: Started Manage Sound Card State (restore and store). Dec 13 09:35:11 xs-4000 alsactl[575]: alsactl 1.1.8 daemon started Dec 13 09:35:11 xs-4000 systemd[1]: Starting dhcpcd on all interfaces... Dec 13 09:35:11 xs-4000 systemd[1]: Starting triggerhappy global hotkey daemon... Dec 13 09:35:11 xs-4000 systemd[1]: Started Volumio Iptables Module. Dec 13 09:35:11 xs-4000 systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Dec 13 09:35:11 xs-4000 systemd[1]: Started Volumio Log Rotation Service. Dec 13 09:35:11 xs-4000 systemd[1]: Starting Login Service... Dec 13 09:35:11 xs-4000 systemd[1]: Starting Save/Restore Sound Card State... Dec 13 09:35:11 xs-4000 systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Dec 13 09:35:11 xs-4000 systemd[1]: Started D-Bus System Message Bus. Dec 13 09:35:11 xs-4000 dhcpcd[582]: Not running dhcpcd because /etc/network/interfaces Dec 13 09:35:11 xs-4000 dhcpcd[582]: defines some interfaces that will use a Dec 13 09:35:11 xs-4000 dhcpcd[582]: DHCP client or static address Dec 13 09:35:11 xs-4000 systemd[1]: Starting WPA supplicant... Dec 13 09:35:11 xs-4000 systemd[1]: Starting Wireless Services... Dec 13 09:35:11 xs-4000 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Dec 13 09:35:11 xs-4000 systemd[1]: Started RPC bind portmap service. Dec 13 09:35:11 xs-4000 systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Dec 13 09:35:11 xs-4000 systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Dec 13 09:35:11 xs-4000 systemd[1]: Failed to start dhcpcd on all interfaces. Dec 13 09:35:11 xs-4000 systemd[1]: hciuart.service: Succeeded. Dec 13 09:35:11 xs-4000 systemd[1]: Started Configure Bluetooth Modems connected by UART. Dec 13 09:35:11 xs-4000 systemd[1]: Started Save/Restore Sound Card State. Dec 13 09:35:11 xs-4000 systemd[1]: Reached target Sound Card. Dec 13 09:35:11 xs-4000 systemd[1]: Starting Raspberry Pi bluetooth helper... Dec 13 09:35:11 xs-4000 systemd[1]: Reached target RPC Port Mapper. Dec 13 09:35:11 xs-4000 systemd[1]: Reached target Remote File Systems (Pre). Dec 13 09:35:11 xs-4000 systemd[1]: Reached target Remote File Systems. Dec 13 09:35:11 xs-4000 systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Dec 13 09:35:11 xs-4000 thd[584]: Unable to parse trigger line: Dec 13 09:35:11 xs-4000 thd[584]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Dec 13 09:35:11 xs-4000 thd[584]: Unable to parse trigger line: Dec 13 09:35:11 xs-4000 thd[584]: Unable to parse trigger line: Dec 13 09:35:11 xs-4000 thd[584]: Found socket passed from systemd Dec 13 09:35:11 xs-4000 sh[490]: wlan0=wlan0 Dec 13 09:35:11 xs-4000 systemd-logind[599]: New seat seat0. Dec 13 09:35:11 xs-4000 avahi-daemon[593]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Dec 13 09:35:11 xs-4000 avahi-daemon[593]: Successfully dropped root privileges. Dec 13 09:35:11 xs-4000 avahi-daemon[593]: avahi-daemon 0.7 starting up. Dec 13 09:35:11 xs-4000 volumio-remote-updater[572]: Error: No active session Dec 13 09:35:11 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:35:11] [info] asio async_connect error: system:111 (Connection refused) Dec 13 09:35:11 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:35:11] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 13 09:35:11 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:35:11] [error] handle_connect error: Underlying Transport Error Dec 13 09:35:11 xs-4000 bthelper[612]: Raspberry Pi BDADDR already set Dec 13 09:35:11 xs-4000 sh[492]: eth0: waiting for carrier Dec 13 09:35:11 xs-4000 dhcpcd[534]: eth0: waiting for carrier Dec 13 09:35:11 xs-4000 kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Dec 13 09:35:11 xs-4000 kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 13 09:35:11 xs-4000 volumio-time-update[568]: volumio-time-update-util: Date not found in response Dec 13 09:35:11 xs-4000 volumio-time-update[568]: volumio-time-update-util: Retrying in 5 seconds... Dec 13 09:35:11 xs-4000 wpa_supplicant[604]: Successfully initialized wpa_supplicant Dec 13 09:35:11 xs-4000 avahi-daemon[593]: Successfully called chroot(). Dec 13 09:35:11 xs-4000 avahi-daemon[593]: Successfully dropped remaining capabilities. Dec 13 09:35:11 xs-4000 systemd[1]: Started Login Service. Dec 13 09:35:11 xs-4000 systemd[1]: Started Avahi mDNS/DNS-SD Stack. Dec 13 09:35:11 xs-4000 systemd[1]: Started WPA supplicant. Dec 13 09:35:11 xs-4000 avahi-daemon[593]: Loading service file /services/volumio.service. Dec 13 09:35:11 xs-4000 systemd[1]: Started triggerhappy global hotkey daemon. Dec 13 09:35:11 xs-4000 systemd[1]: Started Raspberry Pi bluetooth helper. Dec 13 09:35:11 xs-4000 avahi-daemon[593]: Network interface enumeration completed. Dec 13 09:35:11 xs-4000 avahi-daemon[593]: Server startup complete. Host name is xs-4000.local. Local service cookie is 2662340320. Dec 13 09:35:11 xs-4000 volumio[573]: Could not open config: /tmp/upmpdcli.conf Dec 13 09:35:11 xs-4000 avahi-daemon[593]: Service "XS-4000" (/services/volumio.service) successfully established. Dec 13 09:35:11 xs-4000 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 13 09:35:11 xs-4000 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 13 09:35:11 xs-4000 systemd[1]: Started Raise network interfaces. Dec 13 09:35:11 xs-4000 systemd[1]: Starting Bluetooth service... Dec 13 09:35:11 xs-4000 systemd[1]: Reached target Network. Dec 13 09:35:11 xs-4000 systemd[1]: Starting Permit User Sessions... Dec 13 09:35:11 xs-4000 systemd[1]: Starting Network Time Service... Dec 13 09:35:11 xs-4000 systemd[1]: Reached target Network is Online. Dec 13 09:35:11 xs-4000 systemd[1]: Starting LSB: Brings up/down network automatically... Dec 13 09:35:11 xs-4000 systemd[1]: Starting /etc/rc.local Compatibility... Dec 13 09:35:11 xs-4000 systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Dec 13 09:35:11 xs-4000 systemd[1]: Starting Samba NMB Daemon... Dec 13 09:35:11 xs-4000 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 13 09:35:11 xs-4000 systemd[1]: Started Permit User Sessions. Dec 13 09:35:11 xs-4000 systemd[1]: Started /etc/rc.local Compatibility. Dec 13 09:35:11 xs-4000 systemd[1]: Starting Terminate Plymouth Boot Screen... Dec 13 09:35:11 xs-4000 systemd[1]: Starting Hold until boot process finishes up... Dec 13 09:35:11 xs-4000 systemd[1]: iptables.service: Succeeded. Dec 13 09:35:11 xs-4000 systemd[1]: Received SIGRTMIN+21 from PID 196 (plymouthd). Dec 13 09:35:12 xs-4000 systemd[1]: plymouth-quit.service: Succeeded. Dec 13 09:35:12 xs-4000 systemd[1]: Started Terminate Plymouth Boot Screen. Dec 13 09:35:12 xs-4000 systemd[1]: plymouth-quit-wait.service: Succeeded. Dec 13 09:35:12 xs-4000 systemd[1]: Started Hold until boot process finishes up. Dec 13 09:35:12 xs-4000 loadcpufreq[614]: Loading cpufreq kernel modules...done (none). Dec 13 09:35:12 xs-4000 systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Dec 13 09:35:12 xs-4000 systemd[1]: Received SIGRTMIN+21 from PID 196 (n/a). Dec 13 09:35:12 xs-4000 systemd[1]: Starting LSB: set CPUFreq kernel parameters... Dec 13 09:35:12 xs-4000 systemd[1]: Started Getty on tty1. Dec 13 09:35:12 xs-4000 systemd[1]: Reached target Login Prompts. Dec 13 09:35:12 xs-4000 bluetoothd[680]: Bluetooth daemon 5.83 Dec 13 09:35:12 xs-4000 bluetoothd[680]: src/main.c:check_options() Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Dec 13 09:35:12 xs-4000 systemd[1]: Started Bluetooth service. Dec 13 09:35:12 xs-4000 systemd[1]: Reached target Bluetooth. Dec 13 09:35:12 xs-4000 ifplugd(eth0)[739]: ifplugd 0.28 initializing. Dec 13 09:35:12 xs-4000 ifplugd(eth0)[739]: Using interface eth0/E4:5F:01:87:F6:04 with driver (version: 6.6.62-v7l+) Dec 13 09:35:12 xs-4000 ifplugd(eth0)[739]: Using detection mode: SIOCETHTOOL Dec 13 09:35:12 xs-4000 ifplugd(eth0)[739]: Initialization complete, link beat not detected. Dec 13 09:35:12 xs-4000 bluetoothd[680]: Starting SDP server Dec 13 09:35:12 xs-4000 bluetoothd[680]: Excluding (cli) hostname Dec 13 09:35:12 xs-4000 bluetoothd[680]: Excluding (cli) scanparam Dec 13 09:35:12 xs-4000 bluetoothd[680]: Excluding (cli) battery Dec 13 09:35:12 xs-4000 ntpd[688]: ntpd 4.2.8p12@1.3728-o (1): Starting Dec 13 09:35:12 xs-4000 ntpd[688]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Dec 13 09:35:12 xs-4000 ntpd[747]: proto: precision = 0.777 usec (-20) Dec 13 09:35:12 xs-4000 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Dec 13 09:35:12 xs-4000 kernel: Bluetooth: BNEP filters: protocol multicast Dec 13 09:35:12 xs-4000 kernel: Bluetooth: BNEP socket layer initialized Dec 13 09:35:12 xs-4000 kernel: Bluetooth: MGMT ver 1.22 Dec 13 09:35:12 xs-4000 systemd[1]: Started Network Time Service. Dec 13 09:35:12 xs-4000 bluetoothd[680]: Bluetooth management interface 1.22 initialized Dec 13 09:35:12 xs-4000 bluetoothd[680]: Battery Provider Manager created Dec 13 09:35:12 xs-4000 ifplugd[689]: Network Interface Plugging Daemon...start eth0...done. Dec 13 09:35:12 xs-4000 systemd[1]: Started LSB: Brings up/down network automatically. Dec 13 09:35:12 xs-4000 ntpd[747]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Dec 13 09:35:12 xs-4000 ntpd[747]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Dec 13 09:35:12 xs-4000 ntpd[747]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 351 days ago Dec 13 09:35:12 xs-4000 ntpd[747]: Listen and drop on 0 v6wildcard [::]:123 Dec 13 09:35:12 xs-4000 ntpd[747]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Dec 13 09:35:12 xs-4000 ntpd[747]: Listen normally on 2 lo 127.0.0.1:123 Dec 13 09:35:12 xs-4000 ntpd[747]: Listening on routing socket on fd #19 for interface updates Dec 13 09:35:12 xs-4000 ntpd[747]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Dec 13 09:35:12 xs-4000 ntpd[747]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Dec 13 09:35:12 xs-4000 kernel: NET: Registered PF_ALG protocol family Dec 13 09:35:12 xs-4000 cpufrequtils[725]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Dec 13 09:35:12 xs-4000 systemd[1]: Started LSB: set CPUFreq kernel parameters. Dec 13 09:35:12 xs-4000 haveged[533]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Dec 13 09:35:12 xs-4000 haveged[533]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Dec 13 09:35:12 xs-4000 haveged[533]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99798 Dec 13 09:35:12 xs-4000 haveged[533]: haveged: fills: 0, generated: 0 Dec 13 09:35:12 xs-4000 kernel: cryptd: max_cpu_qlen set to 1000 Dec 13 09:35:12 xs-4000 bluetoothd[680]: Failed to set privacy: Rejected (0x0b) Dec 13 09:35:12 xs-4000 nmbd[707]: [2025/12/13 09:35:12.785900, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Dec 13 09:35:12 xs-4000 nmbd[707]: started asyncdns process 776 Dec 13 09:35:12 xs-4000 nmbd[707]: [2025/12/13 09:35:12.787555, 0] ../lib/util/become_daemon.c:149(daemon_status) Dec 13 09:35:12 xs-4000 nmbd[707]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Dec 13 09:35:12 xs-4000 nmbd[707]: [2025/12/13 09:35:12.787682, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Dec 13 09:35:12 xs-4000 nmbd[707]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Dec 13 09:35:12 xs-4000 wireless.js[607]: Cleaning previous... Dec 13 09:35:13 xs-4000 sudo[784]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Dec 13 09:35:13 xs-4000 sudo[784]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:13 xs-4000 sudo[784]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:13 xs-4000 sudo[786]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Dec 13 09:35:13 xs-4000 sudo[786]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:13 xs-4000 ntpd[747]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Dec 13 09:35:13 xs-4000 sudo[786]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:13 xs-4000 wireless.js[607]: Stopped aP Dec 13 09:35:13 xs-4000 sudo[793]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 13 09:35:13 xs-4000 sudo[793]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:13 xs-4000 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 13 09:35:13 xs-4000 sudo[793]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:13 xs-4000 sudo[795]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Dec 13 09:35:13 xs-4000 sudo[795]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:13 xs-4000 sudo[795]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:13 xs-4000 sudo[802]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 13 09:35:13 xs-4000 sudo[802]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:13 xs-4000 sudo[802]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:13 xs-4000 sudo[804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Dec 13 09:35:13 xs-4000 sudo[804]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:14 xs-4000 ntpd[747]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Dec 13 09:35:15 xs-4000 ntpd[747]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Dec 13 09:35:15 xs-4000 systemd[1]: systemd-rfkill.service: Succeeded. Dec 13 09:35:16 xs-4000 ntpd[747]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Dec 13 09:35:16 xs-4000 sudo[804]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:16 xs-4000 wireless.js[607]: SETTING APPROPRIATE REG DOMAIN: DE Dec 13 09:35:16 xs-4000 sudo[809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 13 09:35:16 xs-4000 sudo[809]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:16 xs-4000 sudo[809]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:16 xs-4000 sudo[811]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Dec 13 09:35:16 xs-4000 sudo[811]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:16 xs-4000 sudo[811]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:16 xs-4000 wireless.js[607]: SUCCESSFULLY SET NEW REGDOMAIN: DE Dec 13 09:35:16 xs-4000 wireless.js[607]: Start wireless flow Dec 13 09:35:16 xs-4000 wireless.js[607]: Stopped hotspot (if there).. Dec 13 09:35:16 xs-4000 sudo[816]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Dec 13 09:35:16 xs-4000 sudo[816]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:16 xs-4000 sudo[816]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:16 xs-4000 sudo[818]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Dec 13 09:35:16 xs-4000 sudo[818]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:16 xs-4000 bluetoothd[680]: src/adv_monitor.c:btd_adv_monitor_power_down() Unexpected NULL btd_adv_monitor_manager object upon power down Dec 13 09:35:16 xs-4000 bthelper[612]: [NEW] Media /org/bluez/hci0 Dec 13 09:35:16 xs-4000 bthelper[612]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Dec 13 09:35:16 xs-4000 bthelper[612]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Dec 13 09:35:16 xs-4000 bthelper[612]: hci0 class of device changed: 0x000000 Dec 13 09:35:16 xs-4000 bthelper[612]: hci0 new_settings: ssp br/edr le secure-conn Dec 13 09:35:16 xs-4000 bthelper[612]: [CHG] Controller E4:5F:01:87:F6:07 PowerState: on-disabling Dec 13 09:35:16 xs-4000 bthelper[612]: Changing power off succeeded Dec 13 09:35:16 xs-4000 bthelper[612]: [CHG] Controller E4:5F:01:87:F6:07 PowerState: off Dec 13 09:35:16 xs-4000 bthelper[612]: [CHG] Controller E4:5F:01:87:F6:07 Powered: no Dec 13 09:35:16 xs-4000 bthelper[612]: [CHG] Controller E4:5F:01:87:F6:07 Discovering: no Dec 13 09:35:16 xs-4000 bthelper[612]: [CHG] Controller E4:5F:01:87:F6:07 Class: 0x00000000 (0) Dec 13 09:35:16 xs-4000 bthelper[612]: [NEW] Media /org/bluez/hci0 Dec 13 09:35:16 xs-4000 bthelper[612]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Dec 13 09:35:16 xs-4000 bthelper[612]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Dec 13 09:35:16 xs-4000 bthelper[612]: [CHG] Controller E4:5F:01:87:F6:07 PowerState: off-enabling Dec 13 09:35:16 xs-4000 volumio-time-update[568]: volumio-time-update-util: Fetching time from Volumio... Dec 13 09:35:16 xs-4000 volumio-time-update[568]: volumio-time-update-util: Date not found in response Dec 13 09:35:16 xs-4000 volumio-time-update[568]: volumio-time-update-util: Retrying in 5 seconds... Dec 13 09:35:16 xs-4000 bthelper[612]: hci0 class of device changed: 0x00041c Dec 13 09:35:16 xs-4000 bthelper[612]: [CHG] Controller E4:5F:01:87:F6:07 Class: 0x0000041c (1052) Dec 13 09:35:16 xs-4000 bthelper[612]: hci0 new_settings: powered ssp br/edr le secure-conn Dec 13 09:35:16 xs-4000 bthelper[612]: Changing power on succeeded Dec 13 09:35:16 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:35:16] [info] asio async_connect error: system:111 (Connection refused) Dec 13 09:35:16 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:35:16] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 13 09:35:16 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:35:16] [error] handle_connect error: Underlying Transport Error Dec 13 09:35:16 xs-4000 sudo[818]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:16 xs-4000 wireless.js[607]: DHCP IP Dec 13 09:35:16 xs-4000 wireless.js[607]: Start ap Dec 13 09:35:16 xs-4000 wpa_supplicant[826]: Successfully initialized wpa_supplicant Dec 13 09:35:16 xs-4000 sudo[827]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Dec 13 09:35:16 xs-4000 sudo[827]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:16 xs-4000 dhcpcd[828]: dev: loaded udev Dec 13 09:35:16 xs-4000 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 13 09:35:16 xs-4000 dhcpcd-run-hooks[846]: wlan0: starting wpa_supplicant Dec 13 09:35:17 xs-4000 dhcpcd-run-hooks[851]: wlan0: failed to start wpa_supplicant Dec 13 09:35:17 xs-4000 dhcpcd-run-hooks[852]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Dec 13 09:35:17 xs-4000 dhcpcd[828]: wlan0: connected to Access Point `' Dec 13 09:35:17 xs-4000 dhcpcd[828]: no interfaces have a carrier Dec 13 09:35:17 xs-4000 dhcpcd[828]: forked to background, child pid 862 Dec 13 09:35:17 xs-4000 dhcpcd[862]: eth0: waiting for carrier Dec 13 09:35:17 xs-4000 dhcpcd[862]: wlan0: waiting for carrier Dec 13 09:35:17 xs-4000 sudo[827]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:17 xs-4000 wireless.js[607]: trying... Dec 13 09:35:17 xs-4000 sudo[864]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:17 xs-4000 sudo[864]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:17 xs-4000 sudo[864]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:18 xs-4000 wireless.js[607]: trying... Dec 13 09:35:18 xs-4000 sudo[867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:18 xs-4000 sudo[867]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:18 xs-4000 sudo[867]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:19 xs-4000 wireless.js[607]: trying... Dec 13 09:35:19 xs-4000 sudo[870]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:19 xs-4000 sudo[870]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:19 xs-4000 sudo[870]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:20 xs-4000 wireless.js[607]: trying... Dec 13 09:35:20 xs-4000 sudo[873]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:20 xs-4000 sudo[873]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:20 xs-4000 sudo[873]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:21 xs-4000 volumio-time-update[568]: volumio-time-update-util: Fetching time from Volumio... Dec 13 09:35:21 xs-4000 volumio-time-update[568]: volumio-time-update-util: Date not found in response Dec 13 09:35:21 xs-4000 volumio-time-update[568]: volumio-time-update-util: Retrying in 5 seconds... Dec 13 09:35:21 xs-4000 wireless.js[607]: trying... Dec 13 09:35:21 xs-4000 sudo[881]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:21 xs-4000 sudo[881]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:21 xs-4000 sudo[881]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:22 xs-4000 wireless.js[607]: trying... Dec 13 09:35:22 xs-4000 sudo[884]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:22 xs-4000 sudo[884]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:22 xs-4000 sudo[884]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:23 xs-4000 wpa_supplicant[850]: wlan0: Trying to associate with SSID 'WLAN-PRIVAT.R231' Dec 13 09:35:23 xs-4000 dhcpcd[862]: wlan0: carrier acquired Dec 13 09:35:23 xs-4000 wpa_supplicant[850]: wlan0: Associated with dc:39:6f:6e:d0:97 Dec 13 09:35:23 xs-4000 wpa_supplicant[850]: wlan0: CTRL-EVENT-CONNECTED - Connection to dc:39:6f:6e:d0:97 completed [id=0 id_str=] Dec 13 09:35:23 xs-4000 wpa_supplicant[850]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 13 09:35:23 xs-4000 wpa_supplicant[850]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Dec 13 09:35:23 xs-4000 dhcpcd[862]: DUID 00:01:00:01:2c:2b:45:89:e4:5f:01:87:f6:05 Dec 13 09:35:23 xs-4000 dhcpcd[862]: wlan0: IAID 01:87:f6:05 Dec 13 09:35:23 xs-4000 dhcpcd[862]: wlan0: adding address fe80::4f8c:ca75:ff6c:3231 Dec 13 09:35:23 xs-4000 dhcpcd[862]: ipv6_addaddr1: Permission denied Dec 13 09:35:23 xs-4000 dhcpcd[862]: wlan0: carrier lost Dec 13 09:35:23 xs-4000 dhcpcd[862]: wlan0: carrier acquired Dec 13 09:35:23 xs-4000 dhcpcd[862]: wlan0: connected to Access Point `WLAN-PRIVAT.R231' Dec 13 09:35:23 xs-4000 dhcpcd[862]: wlan0: IAID 01:87:f6:05 Dec 13 09:35:23 xs-4000 dhcpcd[862]: wlan0: rebinding lease of 192.168.178.20 Dec 13 09:35:23 xs-4000 dhcpcd[862]: wlan0: probing address 192.168.178.20/24 Dec 13 09:35:23 xs-4000 dhcpcd[862]: wlan0: soliciting an IPv6 router Dec 13 09:35:23 xs-4000 wireless.js[607]: trying... Dec 13 09:35:23 xs-4000 sudo[900]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:23 xs-4000 sudo[900]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:23 xs-4000 sudo[900]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:24 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:35:24] [info] asio async_connect error: system:111 (Connection refused) Dec 13 09:35:24 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:35:24] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 13 09:35:24 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:35:24] [error] handle_connect error: Underlying Transport Error Dec 13 09:35:24 xs-4000 wireless.js[607]: trying... Dec 13 09:35:24 xs-4000 sudo[903]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:24 xs-4000 sudo[903]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:24 xs-4000 sudo[903]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:25 xs-4000 wireless.js[607]: trying... Dec 13 09:35:25 xs-4000 sudo[906]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:25 xs-4000 sudo[906]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:25 xs-4000 sudo[906]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:26 xs-4000 volumio-time-update[568]: volumio-time-update-util: Fetching time from Volumio... Dec 13 09:35:26 xs-4000 volumio-time-update[568]: volumio-time-update-util: Date not found in response Dec 13 09:35:26 xs-4000 volumio-time-update[568]: volumio-time-update-util: Retrying in 5 seconds... Dec 13 09:35:26 xs-4000 wireless.js[607]: trying... Dec 13 09:35:26 xs-4000 sudo[914]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:26 xs-4000 sudo[914]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:26 xs-4000 sudo[914]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:27 xs-4000 wireless.js[607]: trying... Dec 13 09:35:27 xs-4000 sudo[917]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:27 xs-4000 sudo[917]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:27 xs-4000 sudo[917]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:28 xs-4000 wireless.js[607]: trying... Dec 13 09:35:28 xs-4000 sudo[920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:28 xs-4000 sudo[920]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:28 xs-4000 sudo[920]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:29 xs-4000 dhcpcd[862]: wlan0: leased 192.168.178.20 for 864000 seconds Dec 13 09:35:29 xs-4000 avahi-daemon[593]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.178.20. Dec 13 09:35:29 xs-4000 avahi-daemon[593]: New relevant interface wlan0.IPv4 for mDNS. Dec 13 09:35:29 xs-4000 dhcpcd[862]: wlan0: adding route to 192.168.178.0/24 Dec 13 09:35:29 xs-4000 avahi-daemon[593]: Registering new address record for 192.168.178.20 on wlan0.IPv4. Dec 13 09:35:29 xs-4000 dhcpcd[862]: wlan0: adding default route via 192.168.178.1 Dec 13 09:35:29 xs-4000 wireless.js[607]: trying... Dec 13 09:35:29 xs-4000 sudo[944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 13 09:35:29 xs-4000 sudo[944]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:29 xs-4000 sudo[944]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:29 xs-4000 wireless.js[607]: Connected to: ----WLAN-PRIVAT.R231 Dec 13 09:35:29 xs-4000 wireless.js[607]: ---- Dec 13 09:35:29 xs-4000 sudo[947]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 13 09:35:29 xs-4000 sudo[947]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:29 xs-4000 sudo[947]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:29 xs-4000 wireless.js[607]: ... joined AP, wlan0 IPv4 is 192.168.178.20, ipV6 is undefined Dec 13 09:35:29 xs-4000 wireless.js[607]: It's done! AP Dec 13 09:35:30 xs-4000 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 13 09:35:30 xs-4000 systemd[1]: Started Wireless Services. Dec 13 09:35:30 xs-4000 systemd[1]: Started Volumio Backend Module. Dec 13 09:35:30 xs-4000 systemd[1]: Started Volumio Cpu Tweaker. Dec 13 09:35:30 xs-4000 volumio-cpu-tweak[953]: Setting RT Priority for mpd Dec 13 09:35:30 xs-4000 volumio-cpu-tweak[953]: pid 35's current scheduling policy: SCHED_OTHER Dec 13 09:35:30 xs-4000 volumio-cpu-tweak[953]: pid 35's current scheduling priority: 0 Dec 13 09:35:30 xs-4000 volumio-cpu-tweak[953]: Setting MPD Affinity Dec 13 09:35:30 xs-4000 volumio-cpu-tweak[953]: pid 3's current affinity mask: f Dec 13 09:35:30 xs-4000 volumio-cpu-tweak[953]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Dec 13 09:35:30 xs-4000 volumio-cpu-tweak[953]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Dec 13 09:35:30 xs-4000 systemd[1]: volumio_cpu_tweak.service: Succeeded. Dec 13 09:35:30 xs-4000 ntpd[747]: Listen normally on 3 wlan0 192.168.178.20:123 Dec 13 09:35:30 xs-4000 ntpd[747]: new interface(s) found: waking up resolver Dec 13 09:35:31 xs-4000 volumio[952]: info: ------------------------------------------- Dec 13 09:35:31 xs-4000 volumio[952]: info: ----- Volumio3 ---- Dec 13 09:35:31 xs-4000 volumio[952]: info: ------------------------------------------- Dec 13 09:35:31 xs-4000 volumio[952]: info: ----- System startup ---- Dec 13 09:35:31 xs-4000 volumio[952]: info: ------------------------------------------- Dec 13 09:35:31 xs-4000 volumio-time-update[568]: volumio-time-update-util: Fetching time from Volumio... Dec 13 09:35:31 xs-4000 volumio-time-update[568]: volumio-time-update-util: Setting system time to: 2025-12-13 09:35:57 Dec 13 09:35:31 xs-4000 sudo[982]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-12-13 09:35:57 Dec 13 09:35:31 xs-4000 sudo[982]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:31 xs-4000 dbus-daemon[601]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.8' (uid=0 pid=983 comm="timedatectl set-time 2025-12-13 09:35:57 ") Dec 13 09:35:32 xs-4000 systemd[1]: Starting Time & Date Service... Dec 13 09:35:32 xs-4000 dbus-daemon[601]: [system] Successfully activated service 'org.freedesktop.timedate1' Dec 13 09:35:32 xs-4000 systemd[1]: Started Time & Date Service. Dec 13 09:35:57 xs-4000 systemd-timedated[984]: Changed local time to Sat Dec 13 09:35:57 2025 Dec 13 09:35:57 xs-4000 sudo[982]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:57 xs-4000 volumio-time-update[568]: volumio-time-update-util: System time updated successfully. Dec 13 09:35:57 xs-4000 systemd[1]: Started Volumio Time Update Utility. Dec 13 09:35:57 xs-4000 volumio[952]: info: MYVOLUMIO Environment detected Dec 13 09:35:57 xs-4000 volumio[952]: info: Plugin folders cleanup Dec 13 09:35:57 xs-4000 volumio[952]: info: Scanning into folder /volumio/app/plugins/ Dec 13 09:35:57 xs-4000 volumio[952]: info: Scanning category audio_interface Dec 13 09:35:57 xs-4000 volumio[952]: info: Scanning category miscellanea Dec 13 09:35:57 xs-4000 volumio[952]: info: Scanning category music_service Dec 13 09:35:57 xs-4000 volumio[952]: info: Scanning category plugins.json Dec 13 09:35:57 xs-4000 volumio[952]: info: Scanning category system_controller Dec 13 09:35:57 xs-4000 volumio[952]: info: Scanning category user_interface Dec 13 09:35:57 xs-4000 volumio[952]: info: Scanning into folder /data/plugins/ Dec 13 09:35:57 xs-4000 volumio[952]: info: Scanning category music_service Dec 13 09:35:57 xs-4000 volumio[952]: info: Plugin folders cleanup completed Dec 13 09:35:57 xs-4000 volumio[952]: info: ------------------------------------------- Dec 13 09:35:57 xs-4000 volumio[952]: info: ----- Core plugins startup ---- Dec 13 09:35:57 xs-4000 volumio[952]: info: ------------------------------------------- Dec 13 09:35:57 xs-4000 volumio[952]: info: Loading plugins from folder /volumio/app/plugins/ Dec 13 09:35:57 xs-4000 volumio[952]: info: Adding plugin upnp to MyMusic Plugins Dec 13 09:35:57 xs-4000 volumio[952]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 13 09:35:57 xs-4000 volumio[952]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 13 09:35:57 xs-4000 volumio[952]: info: Loading plugins from folder /data/plugins/ Dec 13 09:35:57 xs-4000 volumio[952]: info: Loading plugin "system"... Dec 13 09:35:57 xs-4000 volumio[952]: info: Loading plugin "appearance"... Dec 13 09:35:57 xs-4000 nmbd[707]: [2025/12/13 09:35:57.699805, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 13 09:35:57 xs-4000 systemd[1]: Started Samba NMB Daemon. Dec 13 09:35:57 xs-4000 nmbd[707]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Dec 13 09:35:57 xs-4000 systemd[1]: Starting Samba Winbind Daemon... Dec 13 09:35:58 xs-4000 winbindd[990]: [2025/12/13 09:35:58.072218, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Dec 13 09:35:58 xs-4000 winbindd[990]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 13 09:35:58 xs-4000 winbindd[990]: [2025/12/13 09:35:58.089948, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 13 09:35:58 xs-4000 systemd[1]: Started Samba Winbind Daemon. Dec 13 09:35:58 xs-4000 winbindd[990]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Dec 13 09:35:58 xs-4000 systemd[1]: Starting Samba SMB Daemon... Dec 13 09:35:58 xs-4000 smbd[995]: [2025/12/13 09:35:58.496040, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 13 09:35:58 xs-4000 systemd[1]: Started Samba SMB Daemon. Dec 13 09:35:58 xs-4000 volumio[952]: info: Loading plugin "network"... Dec 13 09:35:58 xs-4000 volumio[952]: info: Refreshing Cached IP Addresses Dec 13 09:35:58 xs-4000 volumio[952]: info: Loading plugin "services"... Dec 13 09:35:58 xs-4000 volumio[952]: info: Loading plugin "alsa_controller"... Dec 13 09:35:58 xs-4000 smbd[995]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Dec 13 09:35:58 xs-4000 systemd[1]: Reached target Multi-User System. Dec 13 09:35:58 xs-4000 sudo[1005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 13 09:35:58 xs-4000 systemd[1]: Reached target Graphical Interface. Dec 13 09:35:58 xs-4000 sudo[1005]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:58 xs-4000 systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 13 09:35:58 xs-4000 sudo[1005]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:58 xs-4000 sudo[1007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 13 09:35:58 xs-4000 sudo[1007]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:58 xs-4000 sudo[1007]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:58 xs-4000 sudo[1017]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 13 09:35:58 xs-4000 sudo[1017]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:58 xs-4000 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Dec 13 09:35:58 xs-4000 systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 13 09:35:58 xs-4000 systemd[1]: Startup finished in 12.028s (kernel) + 25.602s (userspace) = 37.630s. Dec 13 09:35:58 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 09:35:58 xs-4000 volumio[952]: info: Loading plugin "wizard"... Dec 13 09:35:58 xs-4000 volumio[952]: info: Loading plugin "networkfs"... Dec 13 09:35:58 xs-4000 volumio[952]: info: Starting Udev Watcher for removable devices Dec 13 09:35:58 xs-4000 sudo[1031]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=sven,password=KuSha26Jg,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.52/Music /mnt/NAS/DS224plus Dec 13 09:35:58 xs-4000 sudo[1031]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:35:58 xs-4000 volumio[952]: info: Ignoring mount for partition: boot Dec 13 09:35:58 xs-4000 volumio[952]: info: Ignoring mount for partition: volumio Dec 13 09:35:58 xs-4000 volumio[952]: info: Ignoring mount for partition: volumio_data Dec 13 09:35:58 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 13 09:35:58 xs-4000 volumio[952]: info: Loading plugin "volumio_command_line_client"... Dec 13 09:35:58 xs-4000 volumio[952]: info: Loading plugin "upnp"... Dec 13 09:35:58 xs-4000 volumio[952]: info: [1765614958744] Starting Upmpd Daemon Dec 13 09:35:58 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 13 09:35:58 xs-4000 volumio[952]: info: Loading plugin "my_music"... Dec 13 09:35:58 xs-4000 volumio[952]: info: Loading plugin "mpd"... Dec 13 09:35:58 xs-4000 kernel: Key type cifs.spnego registered Dec 13 09:35:58 xs-4000 kernel: Key type cifs.idmap registered Dec 13 09:35:58 xs-4000 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. Dec 13 09:35:58 xs-4000 kernel: CIFS: Attempting to mount //192.168.178.52/Music Dec 13 09:35:59 xs-4000 volumio[952]: info: Loading plugin "upnp_browser"... Dec 13 09:35:59 xs-4000 sudo[1031]: pam_unix(sudo:session): session closed for user root Dec 13 09:35:59 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:35:59] [connect] Successful connection Dec 13 09:35:59 xs-4000 volumio[952]: info: Loading plugin "alarm-clock"... Dec 13 09:35:59 xs-4000 volumio[952]: info: Loading plugin "airplay_emulation"... Dec 13 09:35:59 xs-4000 volumio[952]: info: Starting Shairport Sync Dec 13 09:35:59 xs-4000 volumio[952]: info: Loading plugin "last_100"... Dec 13 09:35:59 xs-4000 volumio[952]: info: Loading plugin "webradio"... Dec 13 09:35:59 xs-4000 volumio[952]: info: Loading plugin "i2s_dacs"... Dec 13 09:35:59 xs-4000 volumio[952]: info: I2S DAC not set, start Auto-detection Dec 13 09:35:59 xs-4000 volumio[952]: info: Loading plugin "volumiodiscovery"... Dec 13 09:35:59 xs-4000 volumio[952]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 13 09:35:59 xs-4000 volumio[952]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 13 09:35:59 xs-4000 volumio[952]: *** WARNING *** For more information see Dec 13 09:35:59 xs-4000 node[952]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 13 09:35:59 xs-4000 volumio[952]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 13 09:35:59 xs-4000 volumio[952]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 13 09:35:59 xs-4000 volumio[952]: *** WARNING *** For more information see Dec 13 09:35:59 xs-4000 node[952]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 13 09:35:59 xs-4000 node[952]: *** WARNING *** For more information see Dec 13 09:35:59 xs-4000 node[952]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 13 09:35:59 xs-4000 node[952]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 13 09:35:59 xs-4000 node[952]: *** WARNING *** For more information see Dec 13 09:35:59 xs-4000 volumio[952]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 13 09:35:59 xs-4000 volumio[952]: info: Discovery: Started advertising with name: XS-4000 Dec 13 09:35:59 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 13 09:35:59 xs-4000 volumio[952]: info: Loading plugin "spop"... Dec 13 09:36:00 xs-4000 volumio[952]: info: Loading plugin "outputs"... Dec 13 09:36:00 xs-4000 volumio[952]: info: Loading plugin "albumart"... Dec 13 09:36:00 xs-4000 volumio[952]: info: Plugin example_plugin is not enabled Dec 13 09:36:00 xs-4000 volumio[952]: info: Loading plugin "inputs"... Dec 13 09:36:00 xs-4000 volumio[952]: info: Loading plugin "updater_comm"... Dec 13 09:36:00 xs-4000 volumio[952]: info: Plugin mpdemulation is not enabled Dec 13 09:36:00 xs-4000 volumio[952]: info: Loading plugin "rest_api"... Dec 13 09:36:00 xs-4000 volumio[952]: info: Loading plugin "websocket"... Dec 13 09:36:00 xs-4000 volumio[952]: Forking 3 albumart workers Dec 13 09:36:00 xs-4000 volumio[952]: info: Starting Socket.io Server version 2.3.0 Dec 13 09:36:00 xs-4000 volumio[952]: info: Loading i18n strings for locale de Dec 13 09:36:00 xs-4000 volumio[952]: Updating browse sources language Dec 13 09:36:00 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::initPlayerControls Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: Express server listening on port 3000 Dec 13 09:36:01 xs-4000 volumio[952]: [Metrics] WebUI: 5s 200.64ms Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreStateMachine::resetVolumioState Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreStateMachine::getcurrentVolume Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::volumioRetrievevolume Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreStateMachine::pushState Dec 13 09:36:01 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::volumioPushState Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: Volumio Network Manager: Network status updated: 2 Dec 13 09:36:01 xs-4000 volumio-remote-updater[572]: [2025-12-13 09:36:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1765614959 101 Dec 13 09:36:01 xs-4000 volumio[952]: 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: 1 Dec 13 09:36:01 xs-4000 volumio[952]: verbose: New Socket.io Connection to 192.168.178.20 from 192.168.178.27 UA: Mozilla/5.0 (Linux; Android 16; Pixel 6a Build/BP3A.250905.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 13 09:36:01 xs-4000 volumio[952]: verbose: New Socket.io Connection to 192.168.178.20:3000 from 192.168.178.27 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 3 Dec 13 09:36:01 xs-4000 volumio[952]: info: Reloading queue from file Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreStateMachine::setRepeat null single undefined Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreStateMachine::pushState Dec 13 09:36:01 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::volumioPushState Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreStateMachine::setRandom null Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreStateMachine::pushState Dec 13 09:36:01 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::volumioPushState Dec 13 09:36:01 xs-4000 volumio[952]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 13 09:36:01 xs-4000 volumio[952]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03115 Dec 13 09:36:01 xs-4000 volumio[952]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 13 09:36:01 xs-4000 volumio[952]: info: Setting Device type: Raspberry PI Dec 13 09:36:01 xs-4000 volumio[952]: info: Completed loading Core Plugins Dec 13 09:36:01 xs-4000 volumio[952]: info: Preparing to generate the ALSA configuration file Dec 13 09:36:01 xs-4000 volumio[952]: info: Asound.conf file unchanged, so no further update is needed Dec 13 09:36:01 xs-4000 volumio[952]: info: Output device has changed, restarting MPD Dec 13 09:36:01 xs-4000 volumio[952]: Starting albumart workers Dec 13 09:36:01 xs-4000 volumio[952]: Starting albumart workers Dec 13 09:36:01 xs-4000 volumio[952]: Starting albumart workers Dec 13 09:36:01 xs-4000 volumio[952]: info: Output device has changed, restarting Shairport Sync Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 09:36:01 xs-4000 sudo[1105]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 13 09:36:01 xs-4000 sudo[1105]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:01 xs-4000 sudo[1107]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 13 09:36:01 xs-4000 sudo[1105]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:01 xs-4000 sudo[1107]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:01 xs-4000 volumio[952]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 13 09:36:01 xs-4000 volumio[952]: info: ___________ START PLUGINS ___________ Dec 13 09:36:01 xs-4000 volumio[952]: info: ControllerMpd::onStart: Initializing MPD Dec 13 09:36:01 xs-4000 volumio[952]: info: Creating MPD Configuration file Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 13 09:36:01 xs-4000 volumio[952]: info: [1765614961601] CoreMusicLibrary::Adding element Medienserver Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 09:36:01 xs-4000 sudo[1114]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 13 09:36:01 xs-4000 sudo[1114]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 09:36:01 xs-4000 sudo[1114]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:01 xs-4000 sudo[1117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 13 09:36:01 xs-4000 sudo[1117]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:01 xs-4000 systemd[1]: Listening on mpd.socket. Dec 13 09:36:01 xs-4000 systemd[1]: Starting Music Player Daemon... Dec 13 09:36:01 xs-4000 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Dec 13 09:36:01 xs-4000 systemd[1]: mpd.service: Succeeded. Dec 13 09:36:01 xs-4000 systemd[1]: Stopped Music Player Daemon. Dec 13 09:36:01 xs-4000 systemd[1]: Starting Music Player Daemon... Dec 13 09:36:01 xs-4000 volumio[952]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 13 09:36:01 xs-4000 volumio[952]: info: [1765614961772] CoreMusicLibrary::Adding element Last_100 Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 13 09:36:01 xs-4000 volumio[952]: info: [1765614961775] CoreMusicLibrary::Adding element Webradio Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 09:36:01 xs-4000 sudo[1124]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 13 09:36:01 xs-4000 sudo[1124]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 09:36:01 xs-4000 volumio[952]: info: Initializing BBC Radios Dec 13 09:36:01 xs-4000 sudo[1124]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 13 09:36:01 xs-4000 sudo[1124]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 09:36:01 xs-4000 volumio[952]: info: Creating Spotify config file Dec 13 09:36:01 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: Volumio Calling Home Dec 13 09:36:02 xs-4000 volumio[952]: info: Discovery: adding 4879a0c3-9c49-477b-a125-b2f240c4023f Dec 13 09:36:02 xs-4000 volumio[952]: info: Discovery: Found device XS-4000 Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:02 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:02 xs-4000 volumio[952]: verbose: New Socket.io Connection to 192.168.178.20 from 192.168.178.27 UA: Mozilla/5.0 (Linux; Android 16; Pixel 6a Build/BP3A.250905.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Dec 13 09:36:02 xs-4000 volumio[952]: info: MPD Permissions set Dec 13 09:36:02 xs-4000 volumio[952]: info: MPD Permissions set Dec 13 09:36:02 xs-4000 volumio[952]: info: Spotify config file written Dec 13 09:36:02 xs-4000 volumio[952]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 09:36:02 xs-4000 volumio[952]: info: Discovery: Getting this device information Dec 13 09:36:02 xs-4000 sudo[1168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 13 09:36:02 xs-4000 sudo[1168]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:02 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 systemd[1]: Started go-librespot Daemon. Dec 13 09:36:02 xs-4000 sudo[1017]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 go-librespot[1170]: go-librespot daemon starting... Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 sudo[1168]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 13 09:36:02 xs-4000 volumio[952]: info: No need to fix Spotify hosts Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 09:36:02 xs-4000 volumio[952]: info: Discovery: Getting this device information Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:02 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 09:36:02 xs-4000 volumio[952]: info: Discovery: Getting this device information Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:02 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 09:36:02 xs-4000 volumio[952]: info: Starting Shairport Sync Dec 13 09:36:02 xs-4000 volumio[952]: info: Starting Shairport Sync Dec 13 09:36:02 xs-4000 volumio[952]: info: Starting Shairport Sync Dec 13 09:36:02 xs-4000 sudo[1181]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 13 09:36:02 xs-4000 sudo[1181]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:02 xs-4000 sudo[1183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 13 09:36:02 xs-4000 sudo[1183]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:02 xs-4000 sudo[1186]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 13 09:36:02 xs-4000 sudo[1186]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:02 xs-4000 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 13 09:36:02 xs-4000 systemd[1]: shairport-sync.service: Succeeded. Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:02 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:02 xs-4000 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 13 09:36:02 xs-4000 volumio[952]: verbose: New Socket.io Connection to 192.168.178.20:3000 from 192.168.178.27 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Dec 13 09:36:02 xs-4000 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 13 09:36:02 xs-4000 sudo[1181]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 13 09:36:02 xs-4000 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 13 09:36:02 xs-4000 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Dec 13 09:36:02 xs-4000 systemd[1]: shairport-sync.service: Succeeded. Dec 13 09:36:02 xs-4000 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 13 09:36:02 xs-4000 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 13 09:36:02 xs-4000 sudo[1186]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 sudo[1183]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 volumio[952]: info: Volumio called home Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 13 09:36:02 xs-4000 volumio[952]: info: Shairport-Sync Started Dec 13 09:36:02 xs-4000 volumio[952]: Error adding Membership: Error: addMembership EINVAL Dec 13 09:36:02 xs-4000 volumio[952]: info: Shairport-Sync Started Dec 13 09:36:02 xs-4000 volumio[952]: info: Shairport-Sync Started Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Dec 13 09:36:02 xs-4000 sudo[1199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Dec 13 09:36:02 xs-4000 sudo[1199]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:02 xs-4000 sudo[1204]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 13 09:36:02 xs-4000 sudo[1204]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:02 xs-4000 sudo[1204]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 sudo[1211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 13 09:36:02 xs-4000 sudo[1199]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 sudo[1211]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:02 xs-4000 sudo[1211]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 sudo[1223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 13 09:36:02 xs-4000 sudo[1223]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:02 xs-4000 sudo[1223]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 sudo[1218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 13 09:36:02 xs-4000 sudo[1218]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:02 xs-4000 sudo[1227]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 13 09:36:02 xs-4000 sudo[1227]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:02 xs-4000 sudo[1218]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 sudo[1227]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:02 xs-4000 volumio[952]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 13 09:36:02 xs-4000 volumio[952]: SPOTIFY: BQBESOtkTNBig8j1g3Z_XIbtVPMTjvS5AcW52QID1KgkcBYuDC6yQrR5vrVK3rQjjl71crEJouV4R_tZdZf-RMIRWhDbNHrqTboF9LPHsFXpUjk662keTdHHJKRwMPDW0oxI1g8Sw8XvMSuSynnQ9CJ0qEKyuOmrQNfv5151V9WulKTpGznCJnlL6XKl9Z26qUHTk7NptcbY9tOqlusRa1B3TmipsSxzwFTb6xaWIhhzJSKO3DS7KScbrST9hgfmCFr4q2bMDwRl7ZN_MRSNvhF9KPD7mOPzIdb89vzKhBjDngL2iwGVnMit Dec 13 09:36:02 xs-4000 volumio[952]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 13 09:36:02 xs-4000 volumio[952]: info: New Spotify access token = BQBESOtkTNBig8j1g3Z_XIbtVPMTjvS5AcW52QID1KgkcBYuDC6yQrR5vrVK3rQjjl71crEJouV4R_tZdZf-RMIRWhDbNHrqTboF9LPHsFXpUjk662keTdHHJKRwMPDW0oxI1g8Sw8XvMSuSynnQ9CJ0qEKyuOmrQNfv5151V9WulKTpGznCJnlL6XKl9Z26qUHTk7NptcbY9tOqlusRa1B3TmipsSxzwFTb6xaWIhhzJSKO3DS7KScbrST9hgfmCFr4q2bMDwRl7ZN_MRSNvhF9KPD7mOPzIdb89vzKhBjDngL2iwGVnMit Dec 13 09:36:02 xs-4000 volumio[952]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 13 09:36:02 xs-4000 go-librespot[1170]: time="2025-12-13T09:36:02+01:00" level=info msg="running go-librespot 0.4.0" Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 09:36:02 xs-4000 volumio[952]: info: Discovery: Getting this device information Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:02 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 09:36:02 xs-4000 go-librespot[1170]: time="2025-12-13T09:36:02+01:00" level=debug msg="app state loaded" Dec 13 09:36:02 xs-4000 go-librespot[1170]: time="2025-12-13T09:36:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 09:36:02 xs-4000 volumio[952]: info: Discovery: Getting this device information Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:02 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:02 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:02 xs-4000 volumio[952]: verbose: New Socket.io Connection to 192.168.178.20:3000 from 192.168.178.27 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 13 09:36:02 xs-4000 volumio[952]: SPOTIFY: User informations: {"country":"DE","display_name":"K","email":"sven.juhnke@t-online.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/ogra4wfnsahh52kjlsjv9lqcj"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/ogra4wfnsahh52kjlsjv9lqcj","id":"ogra4wfnsahh52kjlsjv9lqcj","images":[],"product":"premium","type":"user","uri":"spotify:user:ogra4wfnsahh52kjlsjv9lqcj"} Dec 13 09:36:02 xs-4000 volumio[952]: info: Spotify Successfully logged in Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 13 09:36:02 xs-4000 volumio[952]: info: [1765614962885] CoreMusicLibrary::Adding element Spotify Dec 13 09:36:02 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 09:36:02 xs-4000 volumio[952]: Cannot find translation for source Spotify Dec 13 09:36:03 xs-4000 go-librespot[1170]: time="2025-12-13T09:36:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 13 09:36:03 xs-4000 go-librespot[1170]: time="2025-12-13T09:36:03+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 13 09:36:03 xs-4000 go-librespot[1170]: time="2025-12-13T09:36:03+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 13 09:36:03 xs-4000 go-librespot[1170]: time="2025-12-13T09:36:03+01:00" level=info msg="zeroconf server listening on port 35261" Dec 13 09:36:03 xs-4000 go-librespot[1170]: time="2025-12-13T09:36:03+01:00" level=debug msg="obtained new client token: AABn2teTpCJ3VZClXN493EPJaWQxDZwmpYDT/QJJv/KQrped2cSSjJx+RHijGJ6qmx0EdF9Ku43tf6/HmQjMFE5cpIyDd0JxlhrbFEVM2SDzr0LJE9Bv6b/oWbAGsWwpkyCdSTHQUIlSnYP6/bfl78LVTyFE633+3yQMoi9eCy8op+Xdz27M7nakbaktwkZNmkyai+IuCKpvorRlE3PH6TJHQArwojqvqPhS237VToVBHc3QLIl12Q==" Dec 13 09:36:03 xs-4000 go-librespot[1170]: time="2025-12-13T09:36:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 13 09:36:03 xs-4000 sudo[1234]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 13 09:36:03 xs-4000 sudo[1234]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:03 xs-4000 sudo[1234]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:03 xs-4000 go-librespot[1170]: time="2025-12-13T09:36:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 13 09:36:03 xs-4000 sudo[1236]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 13 09:36:03 xs-4000 sudo[1236]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:03 xs-4000 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 09:36:03 xs-4000 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 09:36:03 xs-4000 sudo[1236]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:03 xs-4000 volumio[952]: verbose: New Socket.io Connection to 192.168.178.20 from 192.168.178.27 UA: Mozilla/5.0 (Linux; Android 16; Pixel 6a Build/BP3A.250905.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 13 09:36:03 xs-4000 sudo[1240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 13 09:36:03 xs-4000 sudo[1240]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:03 xs-4000 sudo[1240]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:03 xs-4000 sudo[1242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 13 09:36:03 xs-4000 sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:03 xs-4000 sudo[1242]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:03 xs-4000 volumio[952]: verbose: New Socket.io Connection to 192.168.178.20 from 192.168.178.27 UA: Mozilla/5.0 (Linux; Android 16; Pixel 6a Build/BP3A.250905.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetVisibleSources Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:03 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 13 09:36:03 xs-4000 volumio[952]: info: Received Get System Info Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 09:36:03 xs-4000 volumio[952]: info: Discovery: Getting this device information Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:03 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:03 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:03 xs-4000 volumio[952]: info: Listing playlists Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 13 09:36:03 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 13 09:36:03 xs-4000 mpd[1129]: Dec 13 09:36 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 13 09:36:04 xs-4000 systemd[1]: Started Music Player Daemon. Dec 13 09:36:04 xs-4000 sudo[1107]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:04 xs-4000 sudo[1117]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:04 xs-4000 volumio[952]: info: Completed starting Core Plugins Dec 13 09:36:04 xs-4000 volumio[952]: info: ------------------------------------------- Dec 13 09:36:04 xs-4000 volumio[952]: info: ----- MyVolumio plugins startup ---- Dec 13 09:36:04 xs-4000 volumio[952]: info: ------------------------------------------- Dec 13 09:36:04 xs-4000 volumio[952]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 13 09:36:04 xs-4000 volumio[952]: error: MPD error: The expression evaluated to a falsy value: Dec 13 09:36:04 xs-4000 volumio[952]: assert.ok(self.idling) Dec 13 09:36:04 xs-4000 volumio[952]: error: The expression evaluated to a falsy value: Dec 13 09:36:04 xs-4000 volumio[952]: assert.ok(self.idling) Dec 13 09:36:04 xs-4000 volumio[952]: info: MPD running with PID1129 Dec 13 09:36:04 xs-4000 volumio[952]: ,establishing connection Dec 13 09:36:04 xs-4000 volumio[952]: error: updateQueue error: null Dec 13 09:36:04 xs-4000 volumio[952]: error: updateQueue error: null Dec 13 09:36:05 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 13 09:36:05 xs-4000 volumio[952]: info: go-librespot daemon successfully initialized Dec 13 09:36:05 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 13 09:36:05 xs-4000 volumio[952]: info: Received Get System Info Dec 13 09:36:05 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 09:36:05 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 09:36:05 xs-4000 volumio[952]: info: Discovery: Getting this device information Dec 13 09:36:05 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:05 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:05 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 09:36:05 xs-4000 systemd[1]: systemd-fsckd.service: Succeeded. Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Dec 13 09:36:06 xs-4000 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 13 09:36:06 xs-4000 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 13 09:36:06 xs-4000 systemd[1]: Stopped go-librespot Daemon. Dec 13 09:36:06 xs-4000 systemd[1]: Started go-librespot Daemon. Dec 13 09:36:06 xs-4000 go-librespot[1249]: go-librespot daemon starting... Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=info msg="running go-librespot 0.4.0" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="app state loaded" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 09:36:06 xs-4000 sh[492]: timed out Dec 13 09:36:06 xs-4000 dhcpcd[534]: timed out Dec 13 09:36:06 xs-4000 sh[492]: dhcpcd exited Dec 13 09:36:06 xs-4000 dhcpcd[534]: dhcpcd exited Dec 13 09:36:06 xs-4000 sh[492]: ifup: failed to bring up eth0 Dec 13 09:36:06 xs-4000 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Dec 13 09:36:06 xs-4000 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01: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-gew1.spotify.com:80]" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=info msg="zeroconf server listening on port 37071" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="obtained new client token: AAAFyhnFMWmWIrgRxnfZb5+5Cs1scpxh3kPzoFW67eXD4JjFVgT8x7BA3fgey5MkFUKCn5ZVh8X8IqDy1I6xnVRsYQIuxwNqTZQyr2H4aR2LD5YAb1YXM+PfJQVI3pO5AAtJadzupSA+caD1hS1TXgmR2hz7CCpX9AtRdW8LG4ydqUlz2X3IL+lqkEjFBubVCW+sgHOahB8sb7Cd/tGn+utmvdU8qFdfxHdEAnpoka+jjEacDzzQ9O7L" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="completed keyexchange" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="completed challenge" Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=info msg="authenticated AP" username="og*********************cj" Dec 13 09:36:06 xs-4000 volumio[952]: verbose: New Socket.io Connection to 192.168.178.20 from 192.168.178.27 UA: Mozilla/5.0 (Linux; Android 16; Pixel 6a Build/BP3A.250905.014; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Dec 13 09:36:06 xs-4000 volumio[952]: info: Received Get System Info Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 09:36:06 xs-4000 volumio[952]: info: Discovery: Getting this device information Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:06 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 13 09:36:06 xs-4000 volumio[952]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 13 09:36:06 xs-4000 volumio[952]: info: Received Get System Version Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 09:36:06 xs-4000 volumio[952]: info: Received Get System Info Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 09:36:06 xs-4000 volumio[952]: info: Discovery: Getting this device information Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:06 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetVisibleSources Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:06 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 13 09:36:06 xs-4000 volumio[952]: info: Received Get System Info Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 09:36:06 xs-4000 volumio[952]: info: Discovery: Getting this device information Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:06 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 09:36:06 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:06 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:06 xs-4000 volumio[952]: info: Listing playlists Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=info msg="authenticated Login5" username="og*********************cj" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="initializing zeroconf session" username="og*********************cj" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="dealer connection opened" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=trace msg="starting accesspoint recv loop" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=trace msg="starting dealer recv loop" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=trace msg="received accesspoint ping" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 13 09:36:06 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:06+01:00" level=debug msg="received connection id: M2ExNTJiMjEtMzcy...MkE2ODNGMEIxMg==" Dec 13 09:36:07 xs-4000 sudo[1259]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 13 09:36:07 xs-4000 sudo[1259]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:07 xs-4000 sudo[1261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 13 09:36:07 xs-4000 sudo[1261]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:07 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:07+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 13 09:36:07 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:07+01:00" level=debug msg="update volume requested to 25558/65535" Dec 13 09:36:07 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:07+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 13 09:36:07 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:07+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 13 09:36:07 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:07+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 13 09:36:07 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:07+01:00" level=trace msg="received accesspoint pong ack" Dec 13 09:36:07 xs-4000 systemd[1]: Started MPD Monitor Service. Dec 13 09:36:07 xs-4000 mpd_monitor.sh[1264]: MPD Monitor Service: Starting MPD Monitor Service Dec 13 09:36:07 xs-4000 sudo[1259]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:07 xs-4000 volumio[952]: info: Successfully started MPD Monitor Dec 13 09:36:07 xs-4000 systemd[1]: Stopping MPD Monitor Service... Dec 13 09:36:07 xs-4000 systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 13 09:36:07 xs-4000 systemd[1]: mpd_monitor.service: Succeeded. Dec 13 09:36:07 xs-4000 systemd[1]: Stopped MPD Monitor Service. Dec 13 09:36:07 xs-4000 systemd[1]: Started MPD Monitor Service. Dec 13 09:36:07 xs-4000 sudo[1261]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:07 xs-4000 volumio[952]: info: Successfully started MPD Monitor Dec 13 09:36:07 xs-4000 mpd_monitor.sh[1266]: MPD Monitor Service: Starting MPD Monitor Service Dec 13 09:36:07 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:07+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 13 09:36:07 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:07+01:00" level=trace msg="emitting websocket event: volume" Dec 13 09:36:07 xs-4000 volumio[952]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Dec 13 09:36:08 xs-4000 volumio[952]: info: Initializing connection to go-librespot Websocket Dec 13 09:36:08 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:08+01:00" level=debug msg="new websocket client" Dec 13 09:36:08 xs-4000 volumio[952]: info: Connection to go-librespot Websocket established Dec 13 09:36:08 xs-4000 sudo[1285]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 13 09:36:08 xs-4000 sudo[1285]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:08 xs-4000 sudo[1285]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:08 xs-4000 sudo[1287]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 13 09:36:08 xs-4000 sudo[1287]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:08 xs-4000 sudo[1287]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:08 xs-4000 sudo[1291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 13 09:36:08 xs-4000 sudo[1291]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 09:36:08 xs-4000 systemd[1]: Started UPnP Renderer front-end to MPD. Dec 13 09:36:08 xs-4000 sudo[1291]: pam_unix(sudo:session): session closed for user root Dec 13 09:36:08 xs-4000 volumio[952]: info: Upmpdcli Daemon Started Dec 13 09:36:08 xs-4000 volumio[1293]: Generating RSA private key, 4096 bit long modulus (2 primes) Dec 13 09:36:09 xs-4000 volumio[952]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 13 09:36:09 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:09+01:00" level=debug msg="handling transfer player command from e8dc6198fb9dee283bd3462438d37fbab35a9f52" Dec 13 09:36:09 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:09+01:00" level=debug msg="resolved context of track" uri="spotify:playlist:3E2tigwUyjiBEjVNMalFwo" Dec 13 09:36:09 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:09+01:00" level=trace msg="fetched new page 0 with 4 items (list: 4)" uri="spotify:playlist:3E2tigwUyjiBEjVNMalFwo" Dec 13 09:36:09 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:09+01:00" level=debug msg="loading track (paused: true, position: 39996ms)" uri="spotify:track:7t9PLlf9nI2Xo8WRrfcItk" Dec 13 09:36:09 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:09+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 13 09:36:09 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:09+01:00" level=trace msg="emitting websocket event: will_play" Dec 13 09:36:09 xs-4000 volumio[952]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:3E2tigwUyjiBEjVNMalFwo","uri":"spotify:track:7t9PLlf9nI2Xo8WRrfcItk","play_origin":"playlist"}} Dec 13 09:36:09 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:09+01:00" level=debug msg="selected format OGG_VORBIS_320 (e5f5b1bd9bf69649544877a663c3443e0b9f2a7d)" uri="spotify:track:7t9PLlf9nI2Xo8WRrfcItk" Dec 13 09:36:09 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:09+01:00" level=debug msg="requested aes key for file e5f5b1bd9bf69649544877a663c3443e0b9f2a7d, gid: 7t9PLlf9nI2Xo8WRrfcItk" Dec 13 09:36:09 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:09+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 314" Dec 13 09:36:09 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:09+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:7t9PLlf9nI2Xo8WRrfcItk" Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=debug msg="fetched first chunk of 18, total size is 9164460 bytes" uri="spotify:track:7t9PLlf9nI2Xo8WRrfcItk" Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:7t9PLlf9nI2Xo8WRrfcItk" Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=trace msg="seek to 39996ms (diff: 135ms, samples: 1763823, bytes: 1588348)" uri="spotify:track:7t9PLlf9nI2Xo8WRrfcItk" Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=debug msg="created new output device" Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=info msg="loaded track \"Stay There\" (paused: true, position: 39996ms, duration: 233562ms, prefetched: false)" uri="spotify:track:7t9PLlf9nI2Xo8WRrfcItk" Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=trace msg="emitting websocket event: metadata" Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=trace msg="emitting websocket event: active" Dec 13 09:36:10 xs-4000 volumio[952]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7t9PLlf9nI2Xo8WRrfcItk","name":"Stay There","artist_names":["Tonic Walter"],"album_name":"Stay There","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026719a8e813a2c84da10bc7bf","position":39996,"duration":233562,"release_date":"year:2022 month:6 day:17","track_number":1,"disc_number":1}} Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=debug msg="sending successful reply for dealer request" Dec 13 09:36:10 xs-4000 volumio[952]: SPOTIFY: received: {"type":"active","data":null} Dec 13 09:36:10 xs-4000 volumio[952]: info: Aligning Spotify Volume to Volumio Volume Dec 13 09:36:10 xs-4000 volumio[952]: info: CoreCommandRouter::volumioGetState Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Dec 13 09:36:10 xs-4000 volumio[952]: info: CorePlayQueue::getTrack 0 Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=debug msg="fetched chunk 4/17, size: 524288" uri="spotify:track:7t9PLlf9nI2Xo8WRrfcItk" Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 13 09:36:10 xs-4000 go-librespot[1249]: time="2025-12-13T09:36:10+01:00" level=trace msg="emitting websocket event: paused" Dec 13 09:36:10 xs-4000 volumio[952]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:3E2tigwUyjiBEjVNMalFwo","uri":"spotify:track:7t9PLlf9nI2Xo8WRrfcItk","play_origin":"playlist"}} Dec 13 09:36:10 xs-4000 volumio[952]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 13 09:36:10 xs-4000 volumio[952]: TypeError: Cannot read property 'service' of undefined Dec 13 09:36:10 xs-4000 volumio[952]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Dec 13 09:36:10 xs-4000 volumio[952]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Dec 13 09:36:10 xs-4000 volumio[952]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Dec 13 09:36:10 xs-4000 volumio[952]: at WebSocket.emit (events.js:315:20) Dec 13 09:36:10 xs-4000 volumio[952]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Dec 13 09:36:10 xs-4000 volumio[952]: at Receiver.emit (events.js:315:20) Dec 13 09:36:10 xs-4000 volumio[952]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Dec 13 09:36:10 xs-4000 volumio[952]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Dec 13 09:36:10 xs-4000 volumio[952]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Dec 13 09:36:10 xs-4000 volumio[952]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Dec 13 09:36:10 xs-4000 volumio[952]: at writeOrBuffer (internal/streams/writable.js:358:12) Dec 13 09:36:10 xs-4000 volumio[952]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Dec 13 09:36:10 xs-4000 volumio[952]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Dec 13 09:36:10 xs-4000 volumio[952]: at Socket.emit (events.js:315:20) Dec 13 09:36:10 xs-4000 volumio[952]: at addChunk (internal/streams/readable.js:309:12) Dec 13 09:36:10 xs-4000 volumio[952]: at readableAddChunk (internal/streams/readable.js:284:9) Dec 13 09:36:10 xs-4000 volumio[952]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 13 09:36:11 xs-4000 sudo[1319]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-13 09:35 Dec 13 09:36:11 xs-4000 sudo[1319]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"