Jan 26 17:10:00 volumio-100 systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Jan 26 17:10:00 volumio-100 kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 17:10:00 volumio-100 kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Jan 26 17:10:00 volumio-100 kernel: [vc_sm_connected_init]: start Jan 26 17:10:00 volumio-100 kernel: [vc_sm_connected_init]: installed successfully Jan 26 17:10:00 volumio-100 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 17:10:00 volumio-100 systemd[1]: Mounting tmp.mount - /tmp... Jan 26 17:10:00 volumio-100 systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Jan 26 17:10:00 volumio-100 systemd[1]: Mounting var-log.mount - /var/log... Jan 26 17:10:00 volumio-100 (udev-worker)[458]: Network interface NamePolicy= disabled on kernel command line. Jan 26 17:10:00 volumio-100 systemd[1]: Mounting var-spool-cups.mount - /var/spool/cups... Jan 26 17:10:00 volumio-100 systemd[1]: Mounted tmp.mount - /tmp. Jan 26 17:10:00 volumio-100 systemd[1]: Mounted var-log.mount - /var/log. Jan 26 17:10:00 volumio-100 systemd[1]: Mounted var-spool-cups.mount - /var/spool/cups. Jan 26 17:10:00 volumio-100 kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 17:10:00 volumio-100 kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 17:10:00 volumio-100 kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jan 26 17:10:00 volumio-100 systemd[1]: Found device dev-disk-by\x2duuid-3B89\x2d0B23.device - /dev/disk/by-uuid/3B89-0B23. Jan 26 17:10:00 volumio-100 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Jan 26 17:10:00 volumio-100 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Jan 26 17:10:00 volumio-100 systemd[1]: Mounting var-spool-cups-tmp.mount - /var/spool/cups/tmp... Jan 26 17:10:00 volumio-100 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Jan 26 17:10:00 volumio-100 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Jan 26 17:10:00 volumio-100 systemd[1]: Starting systemd-fsck@dev-disk-by\x2duuid-3B89\x2d0B23.service - File System Check on /dev/disk/by-uuid/3B89-0B23... Jan 26 17:10:00 volumio-100 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Jan 26 17:10:00 volumio-100 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jan 26 17:10:00 volumio-100 systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... Jan 26 17:10:00 volumio-100 kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Jan 26 17:10:00 volumio-100 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Jan 26 17:10:00 volumio-100 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Jan 26 17:10:00 volumio-100 systemd[1]: Mounted var-spool-cups-tmp.mount - /var/spool/cups/tmp. Jan 26 17:10:00 volumio-100 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Jan 26 17:10:00 volumio-100 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Jan 26 17:10:00 volumio-100 systemd-journald[428]: Runtime Journal (/run/log/journal/35c4ab2cb79e0973fdebde8c693341bc) is 3.7M, max 30.0M, 26.2M free. Jan 26 17:10:00 volumio-100 systemd-journald[428]: Received client request to flush runtime journal. Jan 26 17:10:00 volumio-100 systemd[1]: Started systemd-fsckd.service - File System Check Daemon to report status. Jan 26 17:10:00 volumio-100 systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. Jan 26 17:10:00 volumio-100 kernel: Bluetooth: Core ver 2.22 Jan 26 17:10:00 volumio-100 kernel: NET: Registered PF_BLUETOOTH protocol family Jan 26 17:10:00 volumio-100 kernel: Bluetooth: HCI device and connection manager initialized Jan 26 17:10:00 volumio-100 kernel: Bluetooth: HCI socket layer initialized Jan 26 17:10:00 volumio-100 kernel: Bluetooth: L2CAP socket layer initialized Jan 26 17:10:00 volumio-100 kernel: Bluetooth: SCO socket layer initialized Jan 26 17:10:00 volumio-100 kernel: Bluetooth: HCI UART driver ver 2.3 Jan 26 17:10:00 volumio-100 kernel: Bluetooth: HCI UART protocol H4 registered Jan 26 17:10:00 volumio-100 kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Jan 26 17:10:00 volumio-100 kernel: Bluetooth: HCI UART protocol Broadcom registered Jan 26 17:10:00 volumio-100 kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Jan 26 17:10:00 volumio-100 kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Jan 26 17:10:00 volumio-100 systemd[1]: Expecting device sys-subsystem-net-devices-eth0.device - /sys/subsystem/net/devices/eth0... Jan 26 17:10:00 volumio-100 systemd[1]: dev-hugepages.mount - Huge Pages File System was skipped because of an unmet condition check (ConditionPathExists=/sys/kernel/mm/hugepages). Jan 26 17:10:00 volumio-100 kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Jan 26 17:10:00 volumio-100 systemd-fsck[551]: fsck.fat 4.2 (2021-01-31) Jan 26 17:10:00 volumio-100 systemd-fsck[551]: /dev/mmcblk0p1: 427 files, 23456/93500 clusters Jan 26 17:10:00 volumio-100 kernel: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Jan 26 17:10:00 volumio-100 kernel: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Jan 26 17:10:00 volumio-100 kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Jan 26 17:10:00 volumio-100 kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Jan 26 17:10:00 volumio-100 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Jan 26 17:10:00 volumio-100 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Jan 26 17:10:00 volumio-100 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Jan 26 17:10:00 volumio-100 systemd[1]: systemd-firstboot.service - First Boot Wizard was skipped because of an unmet condition check (ConditionFirstBoot=yes). Jan 26 17:10:00 volumio-100 systemd[1]: first-boot-complete.target - First Boot Complete was skipped because of an unmet condition check (ConditionFirstBoot=yes). Jan 26 17:10:00 volumio-100 systemd[1]: Finished systemd-fsck@dev-disk-by\x2duuid-3B89\x2d0B23.service - File System Check on /dev/disk/by-uuid/3B89-0B23. Jan 26 17:10:00 volumio-100 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Jan 26 17:10:00 volumio-100 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Jan 26 17:10:00 volumio-100 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Jan 26 17:10:00 volumio-100 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Jan 26 17:10:00 volumio-100 systemd[1]: modprobe@loop.service: Deactivated successfully. Jan 26 17:10:00 volumio-100 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Jan 26 17:10:00 volumio-100 systemd[1]: boot.mount: Directory /boot to mount over is not empty, mounting anyway. Jan 26 17:10:00 volumio-100 systemd[1]: Mounting boot.mount - /boot... Jan 26 17:10:00 volumio-100 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Jan 26 17:10:00 volumio-100 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Jan 26 17:10:00 volumio-100 systemd[1]: Mounted boot.mount - /boot. Jan 26 17:10:00 volumio-100 systemd[1]: Reached target local-fs.target - Local File Systems. Jan 26 17:10:01 volumio-100 kernel: Bluetooth: hci0: BCM: chip id 94 Jan 26 17:10:01 volumio-100 kernel: Bluetooth: hci0: BCM: features 0x2e Jan 26 17:10:01 volumio-100 kernel: Bluetooth: hci0: BCM43430A1 Jan 26 17:10:01 volumio-100 kernel: Bluetooth: hci0: BCM43430A1 (001.002.009) build 0000 Jan 26 17:10:01 volumio-100 systemd[1]: Starting plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data... Jan 26 17:10:01 volumio-100 systemd[1]: Starting plymouth-rotation.service - Plymouth rotation detection for shutdown/reboot... Jan 26 17:10:01 volumio-100 kernel: Bluetooth: hci0: BCM43430A1 'brcm/BCM43430A1.raspberrypi,3-model-b.hcd' Patch Jan 26 17:10:01 volumio-100 systemd[1]: Starting systemd-binfmt.service - Set Up Additional Binary Formats... Jan 26 17:10:01 volumio-100 systemd[1]: systemd-machine-id-commit.service - Commit a transient machine-id on disk was skipped because of an unmet condition check (ConditionPathIsMountPoint=/etc/machine-id). Jan 26 17:10:01 volumio-100 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Jan 26 17:10:01 volumio-100 systemd[1]: Found device sys-subsystem-net-devices-eth0.device - SMSC9512/9514 Fast Ethernet Adapter. Jan 26 17:10:01 volumio-100 systemd[1]: Finished plymouth-read-write.service - Tell Plymouth To Write Out Runtime Data. Jan 26 17:10:01 volumio-100 systemd[1]: Received SIGRTMIN+20 from PID 305 (plymouthd). Jan 26 17:10:01 volumio-100 systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 604 (systemd-binfmt) Jan 26 17:10:01 volumio-100 systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System... Jan 26 17:10:01 volumio-100 systemd[1]: Started ifup@eth0.service - ifup for eth0. Jan 26 17:10:01 volumio-100 systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System. Jan 26 17:10:01 volumio-100 systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats. Jan 26 17:10:01 volumio-100 kernel: brcmfmac: F1 signature read @0x18000000=0x1541a9a6 Jan 26 17:10:01 volumio-100 systemd[1]: Finished plymouth-rotation.service - Plymouth rotation detection for shutdown/reboot. Jan 26 17:10:01 volumio-100 kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1 Jan 26 17:10:01 volumio-100 kernel: usbcore: registered new interface driver brcmfmac Jan 26 17:10:01 volumio-100 systemd[1]: Starting plymouth-start.service - Show Plymouth Boot Screen... Jan 26 17:10:01 volumio-100 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Jan 26 17:10:01 volumio-100 systemd[1]: Mounting run-rpc_pipefs.mount - RPC Pipe File System... Jan 26 17:10:01 volumio-100 systemd[1]: Started haveged.service - Entropy Daemon based on the HAVEGE algorithm. Jan 26 17:10:01 volumio-100 systemd[1]: Starting rpcbind.service - RPC bind portmap service... Jan 26 17:10:01 volumio-100 systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... Jan 26 17:10:01 volumio-100 systemd[1]: Mounted run-rpc_pipefs.mount - RPC Pipe File System. Jan 26 17:10:01 volumio-100 systemd[1]: Reached target rpc_pipefs.target. Jan 26 17:10:01 volumio-100 systemd[1]: rpc-gssd.service - RPC security service for NFS client and server was skipped because of an unmet condition check (ConditionPathExists=/etc/krb5.keytab). Jan 26 17:10:01 volumio-100 systemd[1]: Reached target nfs-client.target - NFS client services. Jan 26 17:10:01 volumio-100 sh[636]: command failed: No such device (-19) Jan 26 17:10:01 volumio-100 systemd[1]: Started plymouth-start.service - Show Plymouth Boot Screen. Jan 26 17:10:01 volumio-100 systemd[1]: systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch was skipped because of an unmet condition check (ConditionPathExists=!/run/plymouth/pid). Jan 26 17:10:01 volumio-100 systemd[1]: Started systemd-ask-password-plymouth.path - Forward Password Requests to Plymouth Directory Watch. Jan 26 17:10:01 volumio-100 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Jan 26 17:10:01 volumio-100 systemd[1]: Reached target paths.target - Path Units. Jan 26 17:10:01 volumio-100 systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. Jan 26 17:10:01 volumio-100 systemd[1]: Reached target sysinit.target - System Initialization. Jan 26 17:10:01 volumio-100 systemd[1]: Started apt-daily.timer - Daily apt download activities. Jan 26 17:10:01 volumio-100 systemd[1]: Started apt-daily-upgrade.timer - Daily apt upgrade and clean activities. Jan 26 17:10:01 volumio-100 systemd[1]: Started dpkg-db-backup.timer - Daily dpkg database backup timer. Jan 26 17:10:01 volumio-100 systemd[1]: Started e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. Jan 26 17:10:01 volumio-100 systemd[1]: Started fstrim.timer - Discard unused blocks once a week. Jan 26 17:10:01 volumio-100 systemd[1]: Started ntpsec-rotate-stats.timer - Rotate ntpd stats daily. Jan 26 17:10:01 volumio-100 systemd[1]: Started setdatetime-helper.timer - Volumio Time Sync Watchdog Timer. Jan 26 17:10:01 volumio-100 systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Jan 26 17:10:01 volumio-100 systemd[1]: Reached target timers.target - Timer Units. Jan 26 17:10:01 volumio-100 systemd[1]: Listening on avahi-daemon.socket - Avahi mDNS/DNS-SD Stack Activation Socket. Jan 26 17:10:01 volumio-100 kernel: brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob available (err=-2) Jan 26 17:10:01 volumio-100 kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Jul 19 2021 03:24:18 version 7.45.98 (TOB) (56df937 CY) FWID 01-8e14b897 Jan 26 17:10:01 volumio-100 systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. Jan 26 17:10:01 volumio-100 systemd[1]: Reached target sockets.target - Socket Units. Jan 26 17:10:01 volumio-100 sh[656]: dhcpcd-9.4.1 starting Jan 26 17:10:01 volumio-100 dhcpcd[656]: dhcpcd-9.4.1 starting Jan 26 17:10:01 volumio-100 systemd[1]: systemd-pcrphase-sysinit.service - TPM2 PCR Barrier (Initialization) was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/StubPcrKernelImage-4a67b082-0a4c-41cf-b6c7-440b29bb8c4f). Jan 26 17:10:01 volumio-100 systemd[1]: Reached target basic.target - Basic System. Jan 26 17:10:01 volumio-100 systemd[1]: alsa-state.service - Manage Sound Card State (restore and store) was skipped because of an unmet condition check (ConditionPathExists=/etc/alsa/state-daemon.conf). Jan 26 17:10:01 volumio-100 sh[656]: DUID 00:01:00:01:30:c6:00:32:b8:27:eb:59:8c:76 Jan 26 17:10:01 volumio-100 dhcpcd[659]: DUID 00:01:00:01:30:c6:00:32:b8:27:eb:59:8c:76 Jan 26 17:10:01 volumio-100 kernel: 8021q: 802.1Q VLAN Support v1.8 Jan 26 17:10:01 volumio-100 systemd[1]: Starting alsa-restore.service - Save/Restore Sound Card State... Jan 26 17:10:01 volumio-100 systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Jan 26 17:10:01 volumio-100 systemd[1]: Starting dbus.service - D-Bus System Message Bus... Jan 26 17:10:01 volumio-100 haveged[638]: haveged: command socket is listening at fd 3 Jan 26 17:10:01 volumio-100 systemd[1]: Starting e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots... Jan 26 17:10:01 volumio-100 systemd[1]: getty-static.service - getty on tty2-tty6 if dbus and logind are not available was skipped because of an unmet condition check (ConditionPathExists=!/usr/bin/dbus-daemon). Jan 26 17:10:01 volumio-100 systemd[1]: headless_wireless.service - Copy user wpa_supplicant.conf was skipped because of an unmet condition check (ConditionPathExists=/boot/wpa_supplicant.conf). Jan 26 17:10:01 volumio-100 systemd[1]: Started iptables.service - Volumio Iptables Module. Jan 26 17:10:01 volumio-100 systemd[1]: Starting rpi-eeprom-update.service - Check for Raspberry Pi EEPROM updates... Jan 26 17:10:01 volumio-100 systemd[1]: Starting systemd-logind.service - User Login Management... Jan 26 17:10:01 volumio-100 kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Jan 26 17:10:01 volumio-100 kernel: smsc95xx 1-1.1:1.0 eth0: Link is Down Jan 26 17:10:01 volumio-100 systemd[1]: Starting triggerhappy.service - triggerhappy global hotkey daemon... Jan 26 17:10:01 volumio-100 dhcpcd[659]: eth0: waiting for carrier Jan 26 17:10:01 volumio-100 sh[656]: eth0: waiting for carrier Jan 26 17:10:01 volumio-100 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 17:10:02 volumio-100 kernel: Bluetooth: hci0: BCM: features 0x2e Jan 26 17:10:02 volumio-100 kernel: Bluetooth: hci0: BCM43438A1 37.4MHz Raspberry Pi 3-0141 Jan 26 17:10:02 volumio-100 kernel: Bluetooth: hci0: BCM43430A1 (001.002.009) build 0508 Jan 26 17:10:02 volumio-100 systemd[1]: Started volumio-remote-updater.service - Volumio Remote OTA Updater. Jan 26 17:10:02 volumio-100 systemd[1]: Starting volumio_rfkill_unblock.service - Manage nl80211 modules blocking state... Jan 26 17:10:02 volumio-100 systemd[1]: volumiossh.service - Volumio SSH enabler was skipped because of an unmet condition check (ConditionPathExistsGlob=/boot/ssh{,.txt}). Jan 26 17:10:02 volumio-100 systemd[1]: Starting wireless.service - Wireless Services... Jan 26 17:10:02 volumio-100 systemd[1]: Started rpcbind.service - RPC bind portmap service. Jan 26 17:10:02 volumio-100 systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Jan 26 17:10:02 volumio-100 systemd[1]: Reached target remote-fs.target - Remote File Systems. Jan 26 17:10:02 volumio-100 systemd[1]: Reached target rpcbind.target - RPC Port Mapper. Jan 26 17:10:02 volumio-100 thd[686]: Unable to parse trigger line: Jan 26 17:10:02 volumio-100 thd[686]: Unable to parse trigger line: Jan 26 17:10:02 volumio-100 systemd[1]: Starting loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling... Jan 26 17:10:02 volumio-100 systemd[1]: systemd-pcrphase.service - TPM2 PCR Barrier (User) was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/StubPcrKernelImage-4a67b082-0a4c-41cf-b6c7-440b29bb8c4f). Jan 26 17:10:02 volumio-100 systemd[1]: Started triggerhappy.service - triggerhappy global hotkey daemon. Jan 26 17:10:02 volumio-100 systemd[1]: Starting th-udev-rebind.service - Late rebind of input devices to triggerhappy... Jan 26 17:10:02 volumio-100 volumio_rfkill_unblock.sh[689]: Volumio WiFi Soft Blocked check script Jan 26 17:10:02 volumio-100 volumio_rfkill_unblock.sh[689]: Check if rfkill is available Jan 26 17:10:02 volumio-100 volumio_rfkill_unblock.sh[689]: Check if rfkill listed devices are already unblocked Jan 26 17:10:02 volumio-100 systemd[1]: th-udev-rebind.service: Deactivated successfully. Jan 26 17:10:02 volumio-100 systemd[1]: Finished th-udev-rebind.service - Late rebind of input devices to triggerhappy. Jan 26 17:10:02 volumio-100 avahi-daemon[670]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Jan 26 17:10:02 volumio-100 avahi-daemon[670]: Successfully dropped root privileges. Jan 26 17:10:02 volumio-100 avahi-daemon[670]: avahi-daemon 0.8 starting up. Jan 26 17:10:02 volumio-100 alsactl[698]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Jan 26 17:10:02 volumio-100 alsactl[698]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Jan 26 17:10:02 volumio-100 alsactl[698]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Jan 26 17:10:02 volumio-100 systemd[1]: Finished alsa-restore.service - Save/Restore Sound Card State. Jan 26 17:10:02 volumio-100 systemd[1]: Reached target sound.target - Sound Card. Jan 26 17:10:02 volumio-100 volumio_rfkill_unblock.sh[689]: nl80211 modules are in the blocked state - unblocking Jan 26 17:10:02 volumio-100 rfkill[706]: unblock set for all Jan 26 17:10:02 volumio-100 volumio_rfkill_unblock.sh[708]: 0: hci0: Bluetooth Jan 26 17:10:02 volumio-100 volumio_rfkill_unblock.sh[708]: Soft blocked: no Jan 26 17:10:02 volumio-100 volumio_rfkill_unblock.sh[708]: Hard blocked: no Jan 26 17:10:02 volumio-100 volumio_rfkill_unblock.sh[708]: 1: phy0: Wireless LAN Jan 26 17:10:02 volumio-100 volumio_rfkill_unblock.sh[708]: Soft blocked: no Jan 26 17:10:02 volumio-100 volumio_rfkill_unblock.sh[708]: Hard blocked: no Jan 26 17:10:02 volumio-100 systemd[1]: Finished volumio_rfkill_unblock.service - Manage nl80211 modules blocking state. Jan 26 17:10:02 volumio-100 rpi-eeprom-update[678]: Device does not a have a Raspberry Pi bootloader EEPROM (e.g. Pi 4 or Pi 5). Skipping bootloader update. Jan 26 17:10:02 volumio-100 systemd[1]: Starting dhcpcd.service - DHCP Client Daemon on all interfaces... Jan 26 17:10:02 volumio-100 systemd[1]: Finished rpi-eeprom-update.service - Check for Raspberry Pi EEPROM updates. Jan 26 17:10:02 volumio-100 systemd[1]: e2scrub_reap.service: Deactivated successfully. Jan 26 17:10:02 volumio-100 systemd[1]: Finished e2scrub_reap.service - Remove Stale Online ext4 Metadata Check Snapshots. Jan 26 17:10:02 volumio-100 systemd[1]: Started dbus.service - D-Bus System Message Bus. Jan 26 17:10:02 volumio-100 avahi-daemon[670]: Successfully called chroot(). Jan 26 17:10:02 volumio-100 avahi-daemon[670]: Successfully dropped remaining capabilities. Jan 26 17:10:02 volumio-100 avahi-daemon[670]: Loading service file /services/volumio.service. Jan 26 17:10:02 volumio-100 avahi-daemon[670]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Jan 26 17:10:02 volumio-100 avahi-daemon[670]: New relevant interface lo.IPv4 for mDNS. Jan 26 17:10:02 volumio-100 avahi-daemon[670]: Network interface enumeration completed. Jan 26 17:10:02 volumio-100 avahi-daemon[670]: Registering new address record for 127.0.0.1 on lo.IPv4. Jan 26 17:10:03 volumio-100 systemd[1]: Starting wpa_supplicant.service - WPA supplicant... Jan 26 17:10:03 volumio-100 systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Jan 26 17:10:03 volumio-100 dhcpcd[710]: dhcpcd-9.4.1 starting Jan 26 17:10:03 volumio-100 dhcpcd[739]: dev: loaded udev Jan 26 17:10:03 volumio-100 systemd-logind[685]: New seat seat0. Jan 26 17:10:03 volumio-100 dhcpcd[739]: DUID 00:01:00:01:30:c6:00:32:b8:27:eb:59:8c:76 Jan 26 17:10:03 volumio-100 systemd[1]: Started systemd-logind.service - User Login Management. Jan 26 17:10:03 volumio-100 systemd[1]: Started dhcpcd.service - DHCP Client Daemon on all interfaces. Jan 26 17:10:03 volumio-100 dhcpcd[739]: eth0: waiting for carrier Jan 26 17:10:03 volumio-100 loadcpufreq[692]: Loading cpufreq kernel modules...done (none). Jan 26 17:10:03 volumio-100 systemd[1]: Started loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling. Jan 26 17:10:03 volumio-100 systemd[1]: Starting cpufrequtils.service - LSB: set CPUFreq kernel parameters... Jan 26 17:10:03 volumio-100 systemd[1]: iptables.service: Deactivated successfully. Jan 26 17:10:03 volumio-100 systemd[1]: Listening on systemd-rfkill.socket - Load/Save RF Kill Switch Status /dev/rfkill Watch. Jan 26 17:10:03 volumio-100 systemd[1]: Starting systemd-rfkill.service - Load/Save RF Kill Switch Status... Jan 26 17:10:03 volumio-100 haveged[638]: haveged: ver: 1.9.14; arch: generic; vend: ; build: (gcc 10.2.1 CTV); collect: 128K Jan 26 17:10:03 volumio-100 haveged[638]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14748/63356 Jan 26 17:10:03 volumio-100 haveged[638]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00156 Jan 26 17:10:03 volumio-100 haveged[638]: haveged: fills: 0, generated: 0 Jan 26 17:10:03 volumio-100 (udev-worker)[457]: Network interface NamePolicy= disabled on kernel command line. Jan 26 17:10:03 volumio-100 wpa_supplicant[728]: Successfully initialized wpa_supplicant Jan 26 17:10:03 volumio-100 systemd[1]: Started wpa_supplicant.service - WPA supplicant. Jan 26 17:10:03 volumio-100 systemd[1]: Expecting device sys-subsystem-net-devices-wlan0.device - /sys/subsystem/net/devices/wlan0... Jan 26 17:10:03 volumio-100 (udev-worker)[455]: hci0: Process '/usr/bin/hciconfig hci0 up' failed with exit code 1. Jan 26 17:10:03 volumio-100 volumio-remote-updater[688]: Volumio OTA Client: 1.7.0 Jan 26 17:10:03 volumio-100 volumio-remote-updater[688]: Error: No active session Jan 26 17:10:03 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:10:03] [info] asio async_connect error: asio.system:111 (Connection refused) Jan 26 17:10:03 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:10:03] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Jan 26 17:10:03 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:10:03] [error] handle_connect error: Connection refused Jan 26 17:10:03 volumio-100 cpufrequtils[763]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Jan 26 17:10:03 volumio-100 systemd[1]: Started systemd-rfkill.service - Load/Save RF Kill Switch Status. Jan 26 17:10:03 volumio-100 systemd[1]: Finished ifupdown-pre.service - Helper to synchronize boot up for ifupdown. Jan 26 17:10:03 volumio-100 systemd[1]: Started cpufrequtils.service - LSB: set CPUFreq kernel parameters. Jan 26 17:10:03 volumio-100 systemd[1]: Found device sys-subsystem-net-devices-wlan0.device - /sys/subsystem/net/devices/wlan0. Jan 26 17:10:03 volumio-100 upmpdcli[687]: Could not open config: /tmp/upmpdcli.conf Jan 26 17:10:03 volumio-100 systemd[1]: Starting bluetooth.service - Bluetooth service... Jan 26 17:10:03 volumio-100 dhcpcd[739]: wlan0: waiting for carrier Jan 26 17:10:03 volumio-100 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled Jan 26 17:10:03 volumio-100 systemd[1]: Started ifup@wlan0.service - ifup for wlan0. Jan 26 17:10:03 volumio-100 systemd[1]: Starting networking.service - Raise network interfaces... Jan 26 17:10:03 volumio-100 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 26 17:10:03 volumio-100 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 26 17:10:03 volumio-100 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 26 17:10:03 volumio-100 kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211 Jan 26 17:10:03 volumio-100 avahi-daemon[670]: Server startup complete. Host name is volumio-100.local. Local service cookie is 2983250816. Jan 26 17:10:04 volumio-100 ifup[820]: ifup: waiting for lock on /run/network/ifstate.wlan0 Jan 26 17:10:04 volumio-100 sh[898]: wlan0=wlan0 Jan 26 17:10:04 volumio-100 bluetoothd[817]: Bluetooth daemon 5.83 Jan 26 17:10:04 volumio-100 systemd[1]: Started bluetooth.service - Bluetooth service. Jan 26 17:10:04 volumio-100 bluetoothd[817]: Starting SDP server Jan 26 17:10:04 volumio-100 bluetoothd[817]: Excluding (cli) sap Jan 26 17:10:04 volumio-100 bluetoothd[817]: Excluding (cli) midi Jan 26 17:10:04 volumio-100 bluetoothd[817]: Excluding (cli) battery Jan 26 17:10:04 volumio-100 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Jan 26 17:10:04 volumio-100 kernel: Bluetooth: BNEP filters: protocol multicast Jan 26 17:10:04 volumio-100 kernel: Bluetooth: BNEP socket layer initialized Jan 26 17:10:04 volumio-100 bluetoothd[817]: Bluetooth management interface 1.23 initialized Jan 26 17:10:04 volumio-100 dbus-daemon[672]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 pid=817 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Jan 26 17:10:04 volumio-100 kernel: Bluetooth: MGMT ver 1.23 Jan 26 17:10:04 volumio-100 bluetoothd[817]: Battery Provider Manager created Jan 26 17:10:04 volumio-100 systemd[1]: Starting bluealsa.service - BlueALSA service... Jan 26 17:10:04 volumio-100 kernel: NET: Registered PF_ALG protocol family Jan 26 17:10:04 volumio-100 systemd[1]: Finished networking.service - Raise network interfaces. Jan 26 17:10:04 volumio-100 systemd[1]: Reached target network.target - Network. Jan 26 17:10:04 volumio-100 systemd[1]: Reached target network-online.target - Network is Online. Jan 26 17:10:04 volumio-100 systemd[1]: Starting ifplugd.service - LSB: Brings up/down network automatically... Jan 26 17:10:04 volumio-100 kernel: cryptd: max_cpu_qlen set to 1000 Jan 26 17:10:04 volumio-100 systemd[1]: Starting nmbd.service - Samba NMB Daemon... Jan 26 17:10:04 volumio-100 systemd[1]: Starting ntpsec.service - Network Time Service... Jan 26 17:10:04 volumio-100 systemd[1]: Starting rc-local.service - /etc/rc.local Compatibility... Jan 26 17:10:04 volumio-100 systemd[1]: Starting rpc-statd-notify.service - Notify NFS peers of a restart... Jan 26 17:10:04 volumio-100 systemd[1]: Starting samba-ad-dc.service - Samba AD Daemon... Jan 26 17:10:04 volumio-100 sm-notify[943]: Version 2.6.2 starting Jan 26 17:10:04 volumio-100 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 26 17:10:04 volumio-100 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 17:10:04 volumio-100 systemd[1]: Starting systemd-hostnamed.service - Hostname Service... Jan 26 17:10:04 volumio-100 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Jan 26 17:10:04 volumio-100 systemd[1]: Started volumio-ipchange.service - Volumio IP Change Monitor. Jan 26 17:10:04 volumio-100 systemd[1]: Starting welcome.service - Show a welcome message on console... Jan 26 17:10:04 volumio-100 avahi-daemon[670]: Service "Volumio 100" (/services/volumio.service) successfully established. Jan 26 17:10:05 volumio-100 systemd[1]: Started rc-local.service - /etc/rc.local Compatibility. Jan 26 17:10:05 volumio-100 systemd[1]: Started rpc-statd-notify.service - Notify NFS peers of a restart. Jan 26 17:10:05 volumio-100 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Jan 26 17:10:05 volumio-100 ntpd[954]: INIT: ntpd ntpsec-1.2.2: Starting Jan 26 17:10:05 volumio-100 ntpd[954]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Jan 26 17:10:05 volumio-100 ntp-systemd-wrapper[954]: 2026-01-26T17:10:05 ntpd[954]: INIT: ntpd ntpsec-1.2.2: Starting Jan 26 17:10:05 volumio-100 ntp-systemd-wrapper[954]: 2026-01-26T17:10:05 ntpd[954]: INIT: Command line: /usr/sbin/ntpd -p /run/ntpd.pid -c /etc/ntpsec/ntp.conf -g -N -u ntpsec:ntpsec Jan 26 17:10:05 volumio-100 systemd[1]: Starting plymouth-quit-wait.service - Hold until boot process finishes up... Jan 26 17:10:05 volumio-100 systemd[1]: Started ntpsec.service - Network Time Service. Jan 26 17:10:05 volumio-100 welcome[963]: Resolved ip:[0] Jan 26 17:10:05 volumio-100 ntpd[974]: INIT: precision = 0.782 usec (-20) Jan 26 17:10:05 volumio-100 ntpd[974]: INIT: successfully locked into RAM Jan 26 17:10:05 volumio-100 ntpd[974]: CONFIG: readconfig: parsing file: /etc/ntpsec/ntp.conf Jan 26 17:10:05 volumio-100 ntpd[974]: CONFIG: restrict nopeer ignored Jan 26 17:10:05 volumio-100 bluetoothd[817]: profiles/audio/bap.c:bap_adapter_probe() BAP requires ISO Socket which is not enabled Jan 26 17:10:05 volumio-100 bluetoothd[817]: bap: Operation not supported (95) Jan 26 17:10:05 volumio-100 ntpd[974]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jan 26 17:10:05 volumio-100 ntpd[974]: CLOCK: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2026-06-28T00:00Z last=2017-01-01T00:00Z ofs=37 Jan 26 17:10:05 volumio-100 ntpd[974]: INIT: Using SO_TIMESTAMPNS(ns) Jan 26 17:10:05 volumio-100 ntpd[974]: IO: Listen and drop on 0 v6wildcard [::]:123 Jan 26 17:10:05 volumio-100 ntpd[974]: IO: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jan 26 17:10:05 volumio-100 ntpd[974]: IO: Listen normally on 2 lo 127.0.0.1:123 Jan 26 17:10:05 volumio-100 ntpd[974]: IO: Listening on routing socket on fd #19 for interface updates Jan 26 17:10:05 volumio-100 bluetoothd[817]: Adv Monitor Manager created with supported features:0x00000000, enabled features:0x00000000, max number of supported monitors:32, max number of supported patterns:16 Jan 26 17:10:05 volumio-100 ifplugd(eth0)[996]: ifplugd 0.28 initializing. Jan 26 17:10:05 volumio-100 ifplugd(eth0)[996]: Using interface eth0/B8:27:EB:0C:D9:23 with driver (version: 6.12.47-v7+) Jan 26 17:10:05 volumio-100 ifplugd(eth0)[996]: Using detection mode: SIOCETHTOOL Jan 26 17:10:05 volumio-100 ifplugd(eth0)[996]: Initialization complete, link beat not detected. Jan 26 17:10:05 volumio-100 ifplugd[933]: Network Interface Plugging Daemon...start eth0...done. Jan 26 17:10:05 volumio-100 systemd[1]: Started ifplugd.service - LSB: Brings up/down network automatically. Jan 26 17:10:05 volumio-100 systemd[1]: Finished welcome.service - Show a welcome message on console. Jan 26 17:10:05 volumio-100 ntpd[974]: INIT: This system has a 32-bit time_t. Jan 26 17:10:05 volumio-100 ntpd[974]: INIT: This ntpd will fail on 2038-01-19T03:14:07Z. Jan 26 17:10:05 volumio-100 ntpd[974]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jan 26 17:10:05 volumio-100 ntpd[974]: INIT: Built with OpenSSL 3.0.9 30 May 2023, 30000090 Jan 26 17:10:05 volumio-100 ntpd[974]: INIT: Running with OpenSSL 3.0.18 30 Sep 2025, 30000120 Jan 26 17:10:05 volumio-100 ntpd[974]: NTSc: Using system default root certificates. Jan 26 17:10:05 volumio-100 ntpd[974]: statistics directory /var/log/ntpsec/ does not exist or is unwriteable, error No such file or directory Jan 26 17:10:05 volumio-100 dbus-daemon[672]: [system] Successfully activated service 'org.freedesktop.hostname1' Jan 26 17:10:05 volumio-100 systemd[1]: Started systemd-hostnamed.service - Hostname Service. Jan 26 17:10:06 volumio-100 bluealsa[923]: ../src/storage.c:90: Initializing persistent storage: /var/lib/bluealsa Jan 26 17:10:06 volumio-100 bluealsa[923]: main.c:663: Starting main dispatching loop Jan 26 17:10:06 volumio-100 systemd[1]: Started bluealsa.service - BlueALSA service. Jan 26 17:10:06 volumio-100 bluealsa[923]: main.c:118: Acquired D-Bus service name: org.bluealsa Jan 26 17:10:06 volumio-100 systemd[1]: Reached target bluetooth.target - Bluetooth Support. Jan 26 17:10:06 volumio-100 bluealsa[923]: bluealsa-dbus.c:358: Registering BlueALSA D-Bus manager: /org/bluealsa Jan 26 17:10:06 volumio-100 ntpd[974]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 17:10:06 volumio-100 bluealsa[923]: bluez.c:153: Registering media application: /org/bluez/hci0 Jan 26 17:10:06 volumio-100 bluealsa[923]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/1 Jan 26 17:10:06 volumio-100 bluealsa[923]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/source/2 Jan 26 17:10:06 volumio-100 bluealsa[923]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/1 Jan 26 17:10:06 volumio-100 bluealsa[923]: bluez.c:743: Exporting media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/2 Jan 26 17:10:06 volumio-100 ntpd[974]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jan 26 17:10:06 volumio-100 ntpd[974]: DNS: dns_check: DNS error: -11, System error Jan 26 17:10:06 volumio-100 ntpd[974]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Jan 26 17:10:06 volumio-100 bluetoothd[817]: Endpoint registered: sender=:1.7 path=/org/bluez/hci0/A2DP/SBC/source/1 Jan 26 17:10:06 volumio-100 bluetoothd[817]: Endpoint registered: sender=:1.7 path=/org/bluez/hci0/A2DP/SBC/sink/2 Jan 26 17:10:06 volumio-100 bluetoothd[817]: Endpoint registered: sender=:1.7 path=/org/bluez/hci0/A2DP/SBC/source/2 Jan 26 17:10:06 volumio-100 bluetoothd[817]: Endpoint registered: sender=:1.7 path=/org/bluez/hci0/A2DP/SBC/sink/1 Jan 26 17:10:07 volumio-100 systemd[1]: samba-ad-dc.service: Skipped due to 'exec-condition'. Jan 26 17:10:07 volumio-100 systemd[1]: Condition check resulted in samba-ad-dc.service - Samba AD Daemon being skipped. Jan 26 17:10:07 volumio-100 nmbd[1022]: [2026/01/26 17:10:07.826366, 0] ../../source3/nmbd/nmbd.c:901(main) Jan 26 17:10:07 volumio-100 nmbd[1022]: nmbd version 4.17.8-Raspbian started. Jan 26 17:10:07 volumio-100 nmbd[1022]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Jan 26 17:10:07 volumio-100 ntpd[974]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 17:10:07 volumio-100 ntpd[974]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jan 26 17:10:07 volumio-100 ntpd[974]: DNS: dns_check: DNS error: -11, System error Jan 26 17:10:07 volumio-100 ntpd[974]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 Jan 26 17:10:07 volumio-100 nmbd[1022]: [2026/01/26 17:10:07.847294, 0] ../../source3/nmbd/asyncdns.c:158(start_async_dns) Jan 26 17:10:07 volumio-100 nmbd[1022]: started asyncdns process 1026 Jan 26 17:10:07 volumio-100 nmbd[1022]: [2026/01/26 17:10:07.849255, 0] ../../lib/util/become_daemon.c:150(daemon_status) Jan 26 17:10:07 volumio-100 nmbd[1022]: daemon_status: daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Jan 26 17:10:07 volumio-100 nmbd[1022]: [2026/01/26 17:10:07.849393, 0] ../../source3/nmbd/nmbd_subnetdb.c:252(create_subnets) Jan 26 17:10:07 volumio-100 nmbd[1022]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jan 26 17:10:08 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Single Network Mode enabled (default) - only one network device can be active at a time between ethernet and wireless Jan 26 17:10:08 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Jan 26 17:10:08 volumio-100 systemd[1]: systemd-rfkill.service: Deactivated successfully. Jan 26 17:10:08 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:10:08] [info] asio async_connect error: asio.system:111 (Connection refused) Jan 26 17:10:08 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:10:08] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Jan 26 17:10:08 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:10:08] [error] handle_connect error: Connection refused Jan 26 17:10:08 volumio-100 ntpd[974]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 17:10:08 volumio-100 ntpd[974]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jan 26 17:10:08 volumio-100 ntpd[974]: DNS: dns_check: DNS error: -11, System error Jan 26 17:10:08 volumio-100 ntpd[974]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 Jan 26 17:10:09 volumio-100 sudo[1047]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 26 17:10:09 volumio-100 sudo[1047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:10:09 volumio-100 sudo[1047]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:09 volumio-100 sudo[1049]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 26 17:10:09 volumio-100 sudo[1049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:10:09 volumio-100 sudo[1049]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:09 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Cleaning previous... Jan 26 17:10:09 volumio-100 sudo[1058]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jan 26 17:10:09 volumio-100 sudo[1058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:10:09 volumio-100 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 26 17:10:09 volumio-100 sudo[1058]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:09 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Jan 26 17:10:09 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 3ms Jan 26 17:10:09 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: b8:27:eb:59:8c:76) Jan 26 17:10:09 volumio-100 ntpd[974]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 17:10:09 volumio-100 ntpd[974]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jan 26 17:10:09 volumio-100 ntpd[974]: DNS: dns_check: DNS error: -11, System error Jan 26 17:10:09 volumio-100 ntpd[974]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 Jan 26 17:10:09 volumio-100 sudo[1066]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Jan 26 17:10:09 volumio-100 sudo[1066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:10:09 volumio-100 sudo[1066]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:09 volumio-100 sudo[1074]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Jan 26 17:10:09 volumio-100 sudo[1074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:10:10 volumio-100 sudo[1074]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:10 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: SETTING APPROPRIATE REG DOMAIN: ES Jan 26 17:10:10 volumio-100 sudo[1086]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set ES Jan 26 17:10:10 volumio-100 sudo[1086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:10:10 volumio-100 sudo[1086]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:10 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: SUCCESSFULLY SET NEW REGDOMAIN: ES Jan 26 17:10:10 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Start wireless flow Jan 26 17:10:10 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Stopped hotspot (if there).. Jan 26 17:10:10 volumio-100 sudo[1094]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 26 17:10:10 volumio-100 sudo[1094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:10:10 volumio-100 sudo[1094]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:10 volumio-100 sudo[1096]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 26 17:10:10 volumio-100 sudo[1096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:10:11 volumio-100 sudo[1096]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:11 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Jan 26 17:10:11 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: STAGE 1: wlan0 validated and ready (MAC: b8:27:eb:59:8c:76, USB: false) Jan 26 17:10:11 volumio-100 wpa_supplicant[1102]: Successfully initialized wpa_supplicant Jan 26 17:10:11 volumio-100 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 26 17:10:11 volumio-100 sudo[1114]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jan 26 17:10:11 volumio-100 sudo[1114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:10:11 volumio-100 sudo[1114]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:12 volumio-100 wpa_supplicant[1111]: wlan0: Trying to associate with 9c:9d:7e:4a:ed:8e (SSID='CASA' freq=2427 MHz) Jan 26 17:10:12 volumio-100 wpa_supplicant[1111]: wlan0: Associated with 9c:9d:7e:4a:ed:8e Jan 26 17:10:12 volumio-100 wpa_supplicant[1111]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jan 26 17:10:12 volumio-100 wpa_supplicant[1111]: wlan0: WPA: Key negotiation completed with 9c:9d:7e:4a:ed:8e [PTK=CCMP GTK=TKIP] Jan 26 17:10:12 volumio-100 wpa_supplicant[1111]: wlan0: CTRL-EVENT-CONNECTED - Connection to 9c:9d:7e:4a:ed:8e completed [id=0 id_str=] Jan 26 17:10:12 volumio-100 dhcpcd[739]: wlan0: carrier acquired Jan 26 17:10:12 volumio-100 dhcpcd[739]: wlan0: connected to Access Point: CASA Jan 26 17:10:12 volumio-100 dhcpcd[739]: wlan0: IAID eb:59:8c:76 Jan 26 17:10:12 volumio-100 dhcpcd[739]: wlan0: adding address fe80::b003:ecce:ca59:2d42 Jan 26 17:10:12 volumio-100 dhcpcd[739]: ipv6_addaddr1: Permission denied Jan 26 17:10:12 volumio-100 dhcpcd[739]: wlan0: probing address 192.168.31.126/24 Jan 26 17:10:12 volumio-100 wpa_supplicant[1111]: wlan0: CTRL-EVENT-DISCONNECTED bssid=9c:9d:7e:4a:ed:8e reason=3 locally_generated=1 Jan 26 17:10:12 volumio-100 dhcpcd[739]: wlan0: carrier lost - roaming Jan 26 17:10:12 volumio-100 wpa_supplicant[1111]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Jan 26 17:10:12 volumio-100 wpa_supplicant[1111]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jan 26 17:10:12 volumio-100 wpa_supplicant[1111]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=ES Jan 26 17:10:12 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: DHCP IP fallback Jan 26 17:10:12 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: STAGE 2: Starting event-driven WPA state monitor Jan 26 17:10:12 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: WpaStateMachine: Starting state monitor for wlan0 Jan 26 17:10:13 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: WpaStateMachine: State transition: NULL -> SCANNING (duration: 0ms) Jan 26 17:10:13 volumio-100 wpa_supplicant[1111]: wlan0: Trying to associate with 28:d1:27:4d:2a:8e (SSID='CASA' freq=2427 MHz) Jan 26 17:10:13 volumio-100 bash[951]: setdatetime-helper: all HTTPS Date fallbacks failed Jan 26 17:10:13 volumio-100 systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 26 17:10:13 volumio-100 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 26 17:10:13 volumio-100 systemd[1]: setdatetime-helper.service: Consumed 1.369s CPU time. Jan 26 17:10:13 volumio-100 dhcpcd[739]: wlan0: soliciting an IPv6 router Jan 26 17:10:13 volumio-100 wpa_supplicant[1111]: wlan0: Associated with 28:d1:27:4d:2a:8e Jan 26 17:10:13 volumio-100 wpa_supplicant[1111]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jan 26 17:10:13 volumio-100 wpa_supplicant[1111]: wlan0: WPA: Key negotiation completed with 28:d1:27:4d:2a:8e [PTK=CCMP GTK=TKIP] Jan 26 17:10:13 volumio-100 wpa_supplicant[1111]: wlan0: CTRL-EVENT-CONNECTED - Connection to 28:d1:27:4d:2a:8e completed [id=0 id_str=] Jan 26 17:10:13 volumio-100 dhcpcd[739]: wlan0: carrier acquired Jan 26 17:10:13 volumio-100 dhcpcd[739]: wlan0: IAID eb:59:8c:76 Jan 26 17:10:13 volumio-100 dhcpcd[739]: wlan0: probing address 192.168.31.126/24 Jan 26 17:10:13 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: WpaStateMachine: State transition: SCANNING -> COMPLETED (duration: 513ms) Jan 26 17:10:13 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: WpaStateMachine: COMPLETED - connection successful Jan 26 17:10:13 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: STAGE 2: Connection successful - Connected to 28:d1:27:4d:2a:8e Jan 26 17:10:13 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Onboard WiFi adapter detected, using standard dhcpcd flow Jan 26 17:10:14 volumio-100 dhcpcd[739]: wlan0: soliciting an IPv6 router Jan 26 17:10:14 volumio-100 sudo[1149]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd wlan0 Jan 26 17:10:14 volumio-100 sudo[1149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:10:14 volumio-100 dhcpcd[739]: control command: /sbin/dhcpcd wlan0 Jan 26 17:10:14 volumio-100 sudo[1149]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:14 volumio-100 dhcpcd[739]: control_free: No such file or directory Jan 26 17:10:16 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:10:16] [info] asio async_connect error: asio.system:111 (Connection refused) Jan 26 17:10:16 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:10:16] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Jan 26 17:10:16 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:10:16] [error] handle_connect error: Connection refused Jan 26 17:10:16 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Start ap Jan 26 17:10:17 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Notified systemd about wireless ready Jan 26 17:10:17 volumio-100 systemd[1]: Started wireless.service - Wireless Services. Jan 26 17:10:17 volumio-100 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 26 17:10:17 volumio-100 systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 17:10:17 volumio-100 systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Jan 26 17:10:17 volumio-100 systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Jan 26 17:10:17 volumio-100 systemd[1]: Received SIGRTMIN+21 from PID 305 (plymouthd). Jan 26 17:10:17 volumio-100 systemd[1]: Received SIGRTMIN+21 from PID 305 (plymouthd). Jan 26 17:10:17 volumio-100 systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Jan 26 17:10:17 volumio-100 systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Jan 26 17:10:17 volumio-100 systemd[1]: Started getty@tty1.service - Getty on tty1. Jan 26 17:10:17 volumio-100 systemd[1]: Reached target getty.target - Login Prompts. Jan 26 17:10:17 volumio-100 volumio-cpu-tweak[1161]: Setting RT Priority for mpd Jan 26 17:10:17 volumio-100 volumio-cpu-tweak[1176]: pid 35's current scheduling policy: SCHED_OTHER Jan 26 17:10:17 volumio-100 volumio-cpu-tweak[1176]: pid 35's current scheduling priority: 0 Jan 26 17:10:17 volumio-100 volumio-cpu-tweak[1161]: Setting MPD Affinity Jan 26 17:10:17 volumio-100 volumio-cpu-tweak[1177]: pid 3's current affinity mask: f Jan 26 17:10:17 volumio-100 volumio-cpu-tweak[1161]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Jan 26 17:10:17 volumio-100 volumio-cpu-tweak[1161]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Jan 26 17:10:17 volumio-100 systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Jan 26 17:10:17 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: trying... Jan 26 17:10:18 volumio-100 sudo[1190]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 17:10:18 volumio-100 sudo[1190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:10:18 volumio-100 sudo[1190]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:18 volumio-100 sudo[1193]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 17:10:18 volumio-100 sudo[1193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:10:18 volumio-100 sudo[1193]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:18 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Jan 26 17:10:18 volumio-100 avahi-daemon[670]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.31.126. Jan 26 17:10:18 volumio-100 dhcpcd[739]: wlan0: using static address 192.168.31.126/24 Jan 26 17:10:18 volumio-100 avahi-daemon[670]: New relevant interface wlan0.IPv4 for mDNS. Jan 26 17:10:18 volumio-100 avahi-daemon[670]: Registering new address record for 192.168.31.126 on wlan0.IPv4. Jan 26 17:10:18 volumio-100 dhcpcd[739]: wlan0: adding route to 192.168.31.0/24 Jan 26 17:10:18 volumio-100 dhcpcd[739]: wlan0: adding default route via 192.168.31.1 Jan 26 17:10:18 volumio-100 systemd[1]: welcome.service: Deactivated successfully. Jan 26 17:10:18 volumio-100 systemd[1]: Stopped welcome.service - Show a welcome message on console. Jan 26 17:10:18 volumio-100 systemd[1]: Stopping welcome.service - Show a welcome message on console... Jan 26 17:10:18 volumio-100 systemd[1]: Starting welcome.service - Show a welcome message on console... Jan 26 17:10:18 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: trying... Jan 26 17:10:18 volumio-100 systemd[1]: Started nmbd.service - Samba NMB Daemon. Jan 26 17:10:18 volumio-100 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Jan 26 17:10:18 volumio-100 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 17:10:18 volumio-100 welcome[1205]: Resolved ip:[1] 192.168.31.126 Jan 26 17:10:19 volumio-100 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 17:10:19 volumio-100 systemd[1]: Starting winbind.service - Samba Winbind Daemon... Jan 26 17:10:19 volumio-100 systemd[1]: Finished welcome.service - Show a welcome message on console. Jan 26 17:10:19 volumio-100 systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Jan 26 17:10:19 volumio-100 upmpdcli[1219]: Could not open config: /tmp/upmpdcli.conf Jan 26 17:10:19 volumio-100 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 26 17:10:19 volumio-100 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 26 17:10:19 volumio-100 sudo[1233]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 17:10:19 volumio-100 sudo[1233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:10:19 volumio-100 sudo[1233]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:19 volumio-100 sudo[1236]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 17:10:19 volumio-100 sudo[1236]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:10:19 volumio-100 sudo[1236]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:19 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: ... wlan0 IPv4 is 192.168.31.126, ipV6 is undefined Jan 26 17:10:19 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Connected to SSID: CASA Jan 26 17:10:19 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: It's done! AP Jan 26 17:10:19 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Restarting avahi-daemon... Jan 26 17:10:19 volumio-100 sudo[1241]: root : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart avahi-daemon Jan 26 17:10:19 volumio-100 sudo[1241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:10:19 volumio-100 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 17:10:19 volumio-100 systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 17:10:19 volumio-100 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 17:10:19 volumio-100 systemd[1]: shairport-sync.service: Consumed 1.594s CPU time. Jan 26 17:10:19 volumio-100 systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Jan 26 17:10:19 volumio-100 avahi-daemon[670]: Got SIGTERM, quitting. Jan 26 17:10:19 volumio-100 avahi-daemon[670]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.31.126. Jan 26 17:10:19 volumio-100 avahi-daemon[670]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Jan 26 17:10:19 volumio-100 avahi-daemon[670]: avahi-daemon 0.8 exiting. Jan 26 17:10:19 volumio-100 systemd[1]: avahi-daemon.service: Deactivated successfully. Jan 26 17:10:19 volumio-100 systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Jan 26 17:10:19 volumio-100 systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Process 670 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Successfully dropped root privileges. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: avahi-daemon 0.8 starting up. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Successfully called chroot(). Jan 26 17:10:19 volumio-100 systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Successfully dropped remaining capabilities. Jan 26 17:10:19 volumio-100 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Loading service file /services/volumio.service. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.31.126. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: New relevant interface wlan0.IPv4 for mDNS. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: New relevant interface lo.IPv4 for mDNS. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Network interface enumeration completed. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Registering new address record for 192.168.31.126 on wlan0.IPv4. Jan 26 17:10:19 volumio-100 avahi-daemon[1243]: Registering new address record for 127.0.0.1 on lo.IPv4. Jan 26 17:10:19 volumio-100 sudo[1241]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:19 volumio-100 winbindd[1225]: [2026/01/26 17:10:19.805973, 0] ../../source3/winbindd/winbindd.c:1440(main) Jan 26 17:10:19 volumio-100 winbindd[1225]: winbindd version 4.17.8-Raspbian started. Jan 26 17:10:19 volumio-100 winbindd[1225]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Jan 26 17:10:19 volumio-100 ntpd[974]: IO: Listen normally on 3 wlan0 192.168.31.126:123 Jan 26 17:10:19 volumio-100 ntpd[974]: IO: new interface(s) found: waking up resolver Jan 26 17:10:19 volumio-100 ntpd[974]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 17:10:19 volumio-100 winbindd[1225]: [2026/01/26 17:10:19.839028, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Jan 26 17:10:19 volumio-100 winbindd[1225]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jan 26 17:10:19 volumio-100 wireless.js[690]: WIRELESS.JS - INFO: Notified systemd about wireless ready Jan 26 17:10:19 volumio-100 systemd[1]: Started winbind.service - Samba Winbind Daemon. Jan 26 17:10:19 volumio-100 systemd[1]: Starting smbd.service - Samba SMB Daemon... Jan 26 17:10:20 volumio-100 avahi-daemon[1243]: Server startup complete. Host name is volumio-100.local. Local service cookie is 4028977742. Jan 26 17:10:20 volumio-100 smbd[1273]: [2026/01/26 17:10:20.647825, 0] ../../source3/smbd/server.c:1741(main) Jan 26 17:10:20 volumio-100 smbd[1273]: smbd version 4.17.8-Raspbian started. Jan 26 17:10:20 volumio-100 smbd[1273]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Jan 26 17:10:21 volumio-100 avahi-daemon[1243]: Service "Volumio 100" (/services/volumio.service) successfully established. Jan 26 17:10:22 volumio-100 systemd[1]: Started smbd.service - Samba SMB Daemon. Jan 26 17:10:22 volumio-100 systemd[1]: Reached target multi-user.target - Multi-User System. Jan 26 17:10:22 volumio-100 systemd[1]: Reached target graphical.target - Graphical Interface. Jan 26 17:10:22 volumio-100 systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Jan 26 17:10:22 volumio-100 systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Jan 26 17:10:22 volumio-100 systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Jan 26 17:10:22 volumio-100 systemd[1]: Startup finished in 15.553s (kernel) + 25.399s (userspace) = 40.953s. Jan 26 17:10:22 volumio-100 ntpd[974]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jan 26 17:10:22 volumio-100 ntpd[974]: DNS: Pool taking: 195.95.153.59 Jan 26 17:10:22 volumio-100 ntpd[974]: DNS: Pool taking: 212.227.145.233 Jan 26 17:10:22 volumio-100 ntpd[974]: DNS: Pool taking: 172.233.111.111 Jan 26 17:10:22 volumio-100 ntpd[974]: DNS: Pool taking: 178.215.228.24 Jan 26 17:10:22 volumio-100 ntpd[974]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Jan 26 17:10:23 volumio-100 ntpd[974]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 17:10:24 volumio-100 volumio[1159]: info: ------------------------------------------- Jan 26 17:10:24 volumio-100 volumio[1159]: info: ----- Volumio3 ---- Jan 26 17:10:24 volumio-100 volumio[1159]: info: ------------------------------------------- Jan 26 17:10:24 volumio-100 volumio[1159]: info: ----- System startup ---- Jan 26 17:10:24 volumio-100 volumio[1159]: info: ------------------------------------------- Jan 26 17:10:26 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:10:26] [connect] Successful connection Jan 26 17:10:26 volumio-100 volumio[1159]: info: MYVOLUMIO Environment detected Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: Pool taking: 84.77.195.114 Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: Pool taking: 185.134.42.7 Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: Pool taking: 94.143.139.219 Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: Pool taking: 162.159.200.123 Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: Pool taking: 2001:ba0:221:cb00::1 Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: Pool taking: 2001:ba0:20d:4200::1 Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: Pool taking: 2001:678:8::123 Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: Pool taking: 2001:ba0:21f:4900::1 Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Jan 26 17:10:26 volumio-100 volumio[1159]: info: Plugin folders cleanup Jan 26 17:10:26 volumio-100 volumio[1159]: info: Scanning into folder /volumio/app/plugins/ Jan 26 17:10:26 volumio-100 volumio[1159]: info: Scanning category audio_interface Jan 26 17:10:26 volumio-100 volumio[1159]: info: Scanning category miscellanea Jan 26 17:10:26 volumio-100 volumio[1159]: info: Scanning category music_service Jan 26 17:10:26 volumio-100 volumio[1159]: info: Scanning category plugins.json Jan 26 17:10:26 volumio-100 volumio[1159]: info: Scanning category system_controller Jan 26 17:10:26 volumio-100 volumio[1159]: info: Scanning category user_interface Jan 26 17:10:26 volumio-100 volumio[1159]: info: Scanning into folder /data/plugins/ Jan 26 17:10:26 volumio-100 volumio[1159]: info: Scanning category audio_interface Jan 26 17:10:26 volumio-100 volumio[1159]: info: Scanning category music_service Jan 26 17:10:26 volumio-100 volumio[1159]: info: Plugin folders cleanup completed Jan 26 17:10:26 volumio-100 volumio[1159]: info: ------------------------------------------- Jan 26 17:10:26 volumio-100 volumio[1159]: info: ----- Core plugins startup ---- Jan 26 17:10:26 volumio-100 volumio[1159]: info: ------------------------------------------- Jan 26 17:10:26 volumio-100 volumio[1159]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 17:10:26 volumio-100 volumio[1159]: info: Adding plugin upnp to MyMusic Plugins Jan 26 17:10:26 volumio-100 volumio[1159]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 17:10:26 volumio-100 ntpd[974]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 17:10:26 volumio-100 volumio[1159]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 17:10:26 volumio-100 volumio[1159]: info: Loading plugins from folder /data/plugins/ Jan 26 17:10:26 volumio-100 volumio[1159]: info: Loading plugin "system"... Jan 26 17:10:26 volumio-100 volumio[1159]: info: Loading plugin "appearance"... Jan 26 17:10:51 volumio-100 ntpd[974]: CLOCK: time stepped by 22.480204 Jan 26 17:10:51 volumio-100 ntpd[974]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jan 26 17:10:51 volumio-100 volumio[1159]: info: Loading plugin "network"... Jan 26 17:10:51 volumio-100 volumio[1159]: info: Refreshing Cached IP Addresses Jan 26 17:10:51 volumio-100 volumio[1159]: info: Loading plugin "services"... Jan 26 17:10:51 volumio-100 sudo[1313]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 17:10:51 volumio-100 sudo[1313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:10:51 volumio-100 volumio[1159]: info: Loading plugin "alsa_controller"... Jan 26 17:10:51 volumio-100 sudo[1320]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 17:10:51 volumio-100 sudo[1311]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 17:10:51 volumio-100 sudo[1311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:10:51 volumio-100 sudo[1313]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:51 volumio-100 sudo[1320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:10:51 volumio-100 sudo[1311]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:52 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 17:10:52 volumio-100 volumio[1159]: info: Loading plugin "wizard"... Jan 26 17:10:52 volumio-100 volumio[1159]: info: Loading plugin "networkfs"... Jan 26 17:10:52 volumio-100 volumio[1159]: info: Starting Udev Watcher for removable devices Jan 26 17:10:52 volumio-100 sudo[1345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=joancarles,password=lleida123,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.31.124/Musica /mnt/NAS/Nas Jan 26 17:10:52 volumio-100 sudo[1345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:10:52 volumio-100 volumio[1159]: info: Ignoring mount for partition: boot Jan 26 17:10:52 volumio-100 volumio[1159]: info: Ignoring mount for partition: volumio Jan 26 17:10:52 volumio-100 volumio[1159]: info: Ignoring mount for partition: volumio_data Jan 26 17:10:52 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 17:10:52 volumio-100 volumio[1159]: info: Loading plugin "volumio_command_line_client"... Jan 26 17:10:52 volumio-100 volumio[1159]: info: Loading plugin "upnp"... Jan 26 17:10:52 volumio-100 volumio[1159]: info: [1769443852363] Starting Upmpd Daemon Jan 26 17:10:52 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 17:10:52 volumio-100 volumio[1159]: info: Loading plugin "my_music"... Jan 26 17:10:52 volumio-100 kernel: netfs: FS-Cache loaded Jan 26 17:10:52 volumio-100 volumio[1159]: info: Loading plugin "mpd"... Jan 26 17:10:52 volumio-100 ntpd[974]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jan 26 17:10:52 volumio-100 ntpd[974]: DNS: Pool taking: 217.160.163.33 Jan 26 17:10:52 volumio-100 ntpd[974]: DNS: Pool skipping: 162.159.200.123 Jan 26 17:10:52 volumio-100 ntpd[974]: DNS: Pool skipping: 172.233.111.111 Jan 26 17:10:52 volumio-100 ntpd[974]: DNS: Pool taking: 82.165.173.235 Jan 26 17:10:52 volumio-100 ntpd[974]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Jan 26 17:10:52 volumio-100 kernel: Key type cifs.spnego registered Jan 26 17:10:52 volumio-100 kernel: Key type cifs.idmap registered Jan 26 17:10:52 volumio-100 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. Jan 26 17:10:52 volumio-100 kernel: CIFS: Attempting to mount //192.168.31.124/Musica Jan 26 17:10:52 volumio-100 sudo[1320]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:53 volumio-100 volumio[1159]: info: Loading plugin "upnp_browser"... Jan 26 17:10:53 volumio-100 systemd[1]: systemd-fsckd.service: Deactivated successfully. Jan 26 17:10:53 volumio-100 ntpd[974]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 17:10:53 volumio-100 sudo[1345]: pam_unix(sudo:session): session closed for user root Jan 26 17:10:54 volumio-100 dhcpcd[659]: timed out Jan 26 17:10:54 volumio-100 sh[656]: timed out Jan 26 17:10:54 volumio-100 sh[619]: ifup: failed to bring up eth0 Jan 26 17:10:54 volumio-100 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jan 26 17:10:54 volumio-100 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jan 26 17:10:55 volumio-100 volumio[1159]: info: Starting UPNP Browser Jan 26 17:10:55 volumio-100 volumio[1159]: info: Loading plugin "alarm-clock"... Jan 26 17:10:55 volumio-100 volumio[1159]: info: Plugin airplay_emulation is not enabled Jan 26 17:10:55 volumio-100 volumio[1159]: info: Loading plugin "last_100"... Jan 26 17:10:55 volumio-100 volumio[1159]: info: Loading plugin "webradio"... Jan 26 17:10:56 volumio-100 volumio[1159]: info: Loading plugin "i2s_dacs"... Jan 26 17:10:56 volumio-100 volumio[1159]: info: Loading plugin "volumiodiscovery"... Jan 26 17:10:56 volumio-100 volumio[1159]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 17:10:56 volumio-100 node[1159]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 17:10:56 volumio-100 volumio[1159]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 17:10:56 volumio-100 node[1159]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 17:10:56 volumio-100 volumio[1159]: *** WARNING *** For more information see Jan 26 17:10:56 volumio-100 node[1159]: *** WARNING *** For more information see Jan 26 17:10:56 volumio-100 volumio[1159]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 17:10:56 volumio-100 node[1159]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 17:10:56 volumio-100 volumio[1159]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 17:10:56 volumio-100 node[1159]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 17:10:56 volumio-100 volumio[1159]: *** WARNING *** For more information see Jan 26 17:10:56 volumio-100 node[1159]: *** WARNING *** For more information see Jan 26 17:10:56 volumio-100 volumio[1159]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 17:10:56 volumio-100 volumio[1159]: info: Discovery: Started advertising with name: Volumio 100 Jan 26 17:10:56 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 17:10:56 volumio-100 volumio[1159]: info: Loading plugin "spop"... Jan 26 17:10:56 volumio-100 ntpd[974]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jan 26 17:10:56 volumio-100 ntpd[974]: DNS: Pool skipping: 94.143.139.219 Jan 26 17:10:56 volumio-100 ntpd[974]: DNS: Pool skipping: 212.227.145.233 Jan 26 17:10:56 volumio-100 ntpd[974]: DNS: Pool taking: 5.250.184.159 Jan 26 17:10:56 volumio-100 ntpd[974]: DNS: Pool skipping: 178.215.228.24 Jan 26 17:10:56 volumio-100 ntpd[974]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Jan 26 17:10:56 volumio-100 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Jan 26 17:10:56 volumio-100 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 17:10:56 volumio-100 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 17:10:56 volumio-100 upmpdcli[1386]: Could not open config: /tmp/upmpdcli.conf Jan 26 17:10:56 volumio-100 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 26 17:10:56 volumio-100 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 26 17:10:58 volumio-100 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Jan 26 17:10:59 volumio-100 volumio[1159]: info: Loading plugin "ytcr"... Jan 26 17:11:02 volumio-100 volumio[1159]: info: Loading plugin "outputs"... Jan 26 17:11:02 volumio-100 volumio[1159]: info: Loading plugin "albumart"... Jan 26 17:11:02 volumio-100 volumio[1159]: info: Plugin example_plugin is not enabled Jan 26 17:11:02 volumio-100 volumio[1159]: info: Loading plugin "inputs"... Jan 26 17:11:02 volumio-100 volumio[1159]: info: Loading plugin "updater_comm"... Jan 26 17:11:03 volumio-100 volumio[1159]: info: Plugin mpdemulation is not enabled Jan 26 17:11:03 volumio-100 volumio[1159]: info: Loading plugin "rest_api"... Jan 26 17:11:03 volumio-100 volumio[1159]: info: Loading plugin "websocket"... Jan 26 17:11:03 volumio-100 volumio[1159]: info: Starting Socket.io Server version 1.7.4 Jan 26 17:11:03 volumio-100 volumio[1159]: info: Loading plugin "fusiondsp"... Jan 26 17:11:03 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:11:03] [connect] Successful connection Jan 26 17:11:04 volumio-100 volumio[1159]: info: Applying required configuration parameters for plugin fusiondsp Jan 26 17:11:04 volumio-100 volumio[1404]: Forking 3 albumart workers Jan 26 17:11:04 volumio-100 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 26 17:11:05 volumio-100 volumio[1159]: info: Loading i18n strings for locale ca Jan 26 17:11:05 volumio-100 volumio[1159]: Updating browse sources language Jan 26 17:11:05 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::initPlayerControls Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 17:11:06 volumio-100 volumio[1159]: Express server listening on port 3000 Jan 26 17:11:06 volumio-100 volumio[1159]: [Metrics] WebUI: 20s 765.72ms Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreStateMachine::resetVolumioState Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreStateMachine::getcurrentVolume Jan 26 17:11:06 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 17:11:06 volumio-100 sudo[1467]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 17:11:06 volumio-100 sudo[1467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:06 volumio-100 sudo[1467]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:06 volumio-100 sudo[1465]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 17:11:06 volumio-100 sudo[1465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:06 volumio-100 sudo[1465]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:06 volumio-100 volumio[1159]: info: Volumio Network Manager: Network status updated: 2 Jan 26 17:11:08 volumio-100 volumio[1159]: info: VolumeController:: Volume=41 Mute =false Jan 26 17:11:08 volumio-100 volumio[1159]: info: CoreStateMachine::pushState Jan 26 17:11:08 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:08 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 17:11:08 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioPushState Jan 26 17:11:08 volumio-100 volumio[1159]: info: CoreStateMachine::updateTrackBlock Jan 26 17:11:08 volumio-100 volumio[1159]: info: CorePlayQueue::getTrackBlock Jan 26 17:11:08 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 17:11:08 volumio-100 volumio-remote-updater[688]: [2026-01-26 17:11:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769443863 101 Jan 26 17:11:08 volumio-100 volumio[1159]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 26 17:11:09 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 17:11:09 volumio-100 volumio[1159]: info: Reloading queue from file Jan 26 17:11:09 volumio-100 volumio[1159]: info: CoreStateMachine::setRepeat null single undefined Jan 26 17:11:09 volumio-100 volumio[1159]: info: CoreStateMachine::pushState Jan 26 17:11:09 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:09 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 17:11:09 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioPushState Jan 26 17:11:09 volumio-100 volumio[1159]: info: CoreStateMachine::setRandom null Jan 26 17:11:09 volumio-100 volumio[1159]: info: CoreStateMachine::pushState Jan 26 17:11:09 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:09 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioPushState Jan 26 17:11:09 volumio-100 volumio[1159]: info: Setting Device type: Raspberry PI Jan 26 17:11:09 volumio-100 volumio[1159]: info: Completed loading Core Plugins Jan 26 17:11:09 volumio-100 volumio[1159]: info: Preparing to generate the ALSA configuration file Jan 26 17:11:09 volumio-100 volumio[1159]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 26 17:11:09 volumio-100 volumio[1159]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 26 17:11:09 volumio-100 volumio[1159]: info: Reading ALSA contributions from plugins. Jan 26 17:11:09 volumio-100 volumio[1159]: info: VolumeController:: Volume=41 Mute =false Jan 26 17:11:09 volumio-100 volumio[1159]: info: CoreStateMachine::pushState Jan 26 17:11:09 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:09 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioPushState Jan 26 17:11:10 volumio-100 sudo[1483]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 17:11:10 volumio-100 sudo[1483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:10 volumio-100 volumio[1159]: info: Asound.conf file unchanged, so no further update is needed Jan 26 17:11:10 volumio-100 volumio[1159]: info: Output device has changed, restarting MPD Jan 26 17:11:10 volumio-100 volumio[1159]: info: ___________ START PLUGINS ___________ Jan 26 17:11:10 volumio-100 volumio[1159]: info: ControllerMpd::onStart: Initializing MPD Jan 26 17:11:10 volumio-100 sudo[1487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 17:11:10 volumio-100 volumio[1159]: info: Creating MPD Configuration file Jan 26 17:11:10 volumio-100 sudo[1487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:10 volumio-100 sudo[1487]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:10 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 17:11:10 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 17:11:10 volumio-100 volumio[1159]: info: [1769443870521] CoreMusicLibrary::Adding element Media Servers Jan 26 17:11:10 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 17:11:10 volumio-100 sudo[1489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 17:11:10 volumio-100 sudo[1489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:10 volumio-100 sudo[1491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 17:11:10 volumio-100 volumio[1159]: info: UPNP Browser: Client initialized successfully Jan 26 17:11:10 volumio-100 sudo[1491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:10 volumio-100 sudo[1491]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:10 volumio-100 sudo[1494]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 17:11:10 volumio-100 sudo[1494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:10 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 17:11:10 volumio-100 volumio[1159]: info: [1769443870771] CoreMusicLibrary::Adding element Last_100 Jan 26 17:11:10 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 17:11:10 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 17:11:10 volumio-100 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 17:11:10 volumio-100 volumio[1159]: info: [1769443870817] CoreMusicLibrary::Adding element Webradio Jan 26 17:11:10 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 17:11:10 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 17:11:10 volumio-100 systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 17:11:10 volumio-100 systemd[1]: mpd.service: Deactivated successfully. Jan 26 17:11:10 volumio-100 systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 17:11:10 volumio-100 systemd[1]: mpd.socket: Deactivated successfully. Jan 26 17:11:10 volumio-100 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 17:11:10 volumio-100 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 17:11:11 volumio-100 volumio[1159]: info: Initializing BBC Radios Jan 26 17:11:11 volumio-100 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 17:11:11 volumio-100 systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 17:11:11 volumio-100 sudo[1504]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 17:11:11 volumio-100 sudo[1504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:11:11 volumio-100 sudo[1510]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 26 17:11:11 volumio-100 sudo[1504]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:11 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 17:11:11 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 17:11:11 volumio-100 volumio[1159]: info: Creating Spotify config file Jan 26 17:11:11 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:12 volumio-100 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Jan 26 17:11:12 volumio-100 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 17:11:12 volumio-100 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 26 17:11:12 volumio-100 sudo[1483]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:15 volumio-100 volumio[1159]: info: [ytcr] Data store TTL expired - clearing it... Jan 26 17:11:15 volumio-100 volumio[1414]: Starting albumart workers Jan 26 17:11:16 volumio-100 volumio[1159]: info: FusionDsp - CamillaDSP binary found. Jan 26 17:11:16 volumio-100 volumio[1159]: info: Loading i18n strings for locale ca Jan 26 17:11:16 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 26 17:11:16 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:16 volumio-100 volumio[1159]: info: FusionDsp - mixtype--------------------- Hardware Jan 26 17:11:16 volumio-100 volumio[1159]: info: Volumio Calling Home Jan 26 17:11:16 volumio-100 volumio[1416]: Starting albumart workers Jan 26 17:11:17 volumio-100 volumio[1159]: info: Preparing to generate the ALSA configuration file Jan 26 17:11:17 volumio-100 volumio[1417]: Starting albumart workers Jan 26 17:11:19 volumio-100 volumio[1159]: info: camilladsp service started and running in background, instance 1 Jan 26 17:11:19 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:19 volumio-100 mpd[1511]: 2026-01-26T17:11:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 17:11:19 volumio-100 volumio[1159]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Jan 26 17:11:19 volumio-100 volumio[1159]: info: FusionDsp loaded Jan 26 17:11:19 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 17:11:19 volumio-100 volumio[1159]: error: FusionDsp - Socket connection not established Jan 26 17:11:19 volumio-100 volumio[1159]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 26 17:11:19 volumio-100 volumio[1159]: info: Adding Signal Path Element [object Object] Jan 26 17:11:19 volumio-100 volumio[1159]: info: Adding fusiondspeq DSP Signal Path Element Jan 26 17:11:19 volumio-100 volumio[1159]: info: FusionDsp - ---- installed callbackRead Jan 26 17:11:19 volumio-100 volumio[1159]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 26 17:11:19 volumio-100 systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 17:11:19 volumio-100 volumio[1159]: info: Discovery: adding af98df77-4b75-49a4-bfca-90d41b27230c Jan 26 17:11:19 volumio-100 sudo[1494]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:19 volumio-100 volumio[1159]: info: Discovery: Found device Volumio 100 Jan 26 17:11:19 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioGetState Jan 26 17:11:19 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:19 volumio-100 sudo[1489]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:19 volumio-100 volumio[1159]: info: Discovery: this is already registered, af98df77-4b75-49a4-bfca-90d41b27230c Jan 26 17:11:19 volumio-100 volumio[1159]: info: Discovery: Found device Volumio 100 Jan 26 17:11:19 volumio-100 sudo[1557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 26 17:11:19 volumio-100 sudo[1557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:19 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioGetState Jan 26 17:11:19 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:19 volumio-100 volumio[1159]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 26 17:11:19 volumio-100 volumio[1159]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 26 17:11:19 volumio-100 volumio[1159]: info: Reading ALSA contributions from plugins. Jan 26 17:11:19 volumio-100 systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Jan 26 17:11:19 volumio-100 sudo[1557]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:20 volumio-100 volumio[1159]: info: MPD Permissions set Jan 26 17:11:20 volumio-100 volumio[1159]: info: MPD Permissions set Jan 26 17:11:20 volumio-100 volumio[1159]: info: Upmpdcli Daemon Started Jan 26 17:11:20 volumio-100 volumio[1159]: info: Volumio called home Jan 26 17:11:21 volumio-100 volumio[1159]: info: Spotify config file written Jan 26 17:11:21 volumio-100 sudo[1577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 17:11:21 volumio-100 sudo[1577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:21 volumio-100 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 17:11:21 volumio-100 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 17:11:21 volumio-100 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 17:11:21 volumio-100 go-librespot[1579]: go-librespot daemon starting... Jan 26 17:11:21 volumio-100 sudo[1577]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:22 volumio-100 volumio[1159]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 26 17:11:22 volumio-100 volumio[1159]: info: MPD running with PID1511 Jan 26 17:11:22 volumio-100 volumio[1159]: ,establishing connection Jan 26 17:11:22 volumio-100 go-librespot[1580]: time="2026-01-26T17:11:22+01:00" level=info msg="running go-librespot 0.4.0" Jan 26 17:11:22 volumio-100 go-librespot[1580]: time="2026-01-26T17:11:22+01:00" level=debug msg="app state loaded" Jan 26 17:11:22 volumio-100 go-librespot[1580]: time="2026-01-26T17:11:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:22 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:23 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 17:11:23 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:23 volumio-100 volumio[1159]: info: No need to fix Spotify hosts Jan 26 17:11:24 volumio-100 go-librespot[1580]: time="2026-01-26T17:11:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 26 17:11:24 volumio-100 go-librespot[1580]: time="2026-01-26T17:11:24+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 26 17:11:24 volumio-100 go-librespot[1580]: time="2026-01-26T17:11:24+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 26 17:11:24 volumio-100 go-librespot[1580]: time="2026-01-26T17:11:24+01:00" level=info msg="zeroconf server listening on port 41997" Jan 26 17:11:24 volumio-100 volumio[1159]: error: MPD error: The expression evaluated to a falsy value: Jan 26 17:11:24 volumio-100 volumio[1159]: assert.ok(self.idling) Jan 26 17:11:24 volumio-100 volumio[1159]: error: The expression evaluated to a falsy value: Jan 26 17:11:24 volumio-100 volumio[1159]: assert.ok(self.idling) Jan 26 17:11:24 volumio-100 volumio[1159]: error: MPD error: The expression evaluated to a falsy value: Jan 26 17:11:24 volumio-100 volumio[1159]: assert.ok(self.idling) Jan 26 17:11:24 volumio-100 volumio[1159]: error: The expression evaluated to a falsy value: Jan 26 17:11:24 volumio-100 volumio[1159]: assert.ok(self.idling) Jan 26 17:11:24 volumio-100 volumio[1159]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 26 17:11:25 volumio-100 volumio[1159]: error: updateQueue error: null Jan 26 17:11:25 volumio-100 volumio[1159]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 17:11:25 volumio-100 volumio[1159]: SPOTIFY: BQDIZgDN2HW9AdU347k-wOOOnZtuOJ5lnAvI2IBta5G3VrSTXEaa461AVAmhOvnuAHwrv0nYmw0IoupmQyu3tyNRJG3sskY7ynUwQ4V2opwXnJAsDE3nTPvJWqUIB477GlzQTlGmM6hEjZ5PKa0KPjMvPZpjxHqGekpRUFVctMpb4gASY7153KQa7QIgTN61bBGsPE-eHfQy8veS04uUpes2gvZxu0Id38-n9a9n-Hp_WsjgiRbWsAhksgq3IOzHfp-3uwj3YrIZu02ISWdazdpmGvBzrKheK78BlgN3xvxzyqQ3rZh2AXxJ Jan 26 17:11:25 volumio-100 volumio[1159]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 17:11:25 volumio-100 volumio[1159]: info: New Spotify access token = BQDIZgDN2HW9AdU347k-wOOOnZtuOJ5lnAvI2IBta5G3VrSTXEaa461AVAmhOvnuAHwrv0nYmw0IoupmQyu3tyNRJG3sskY7ynUwQ4V2opwXnJAsDE3nTPvJWqUIB477GlzQTlGmM6hEjZ5PKa0KPjMvPZpjxHqGekpRUFVctMpb4gASY7153KQa7QIgTN61bBGsPE-eHfQy8veS04uUpes2gvZxu0Id38-n9a9n-Hp_WsjgiRbWsAhksgq3IOzHfp-3uwj3YrIZu02ISWdazdpmGvBzrKheK78BlgN3xvxzyqQ3rZh2AXxJ Jan 26 17:11:25 volumio-100 volumio[1159]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 17:11:25 volumio-100 volumio[1159]: error: FusionDsp - Reload WebSocket error: [object Object] Jan 26 17:11:25 volumio-100 volumio[1159]: info: Asound.conf file unchanged, so no further update is needed Jan 26 17:11:25 volumio-100 volumio[1159]: info: Output device has changed, restarting MPD Jan 26 17:11:25 volumio-100 sudo[1624]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 17:11:25 volumio-100 sudo[1624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:25 volumio-100 sudo[1626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 17:11:25 volumio-100 sudo[1626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:26 volumio-100 sudo[1624]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:26 volumio-100 systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 17:11:26 volumio-100 systemd[1]: mpd.service: Deactivated successfully. Jan 26 17:11:26 volumio-100 systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 17:11:26 volumio-100 systemd[1]: mpd.service: Consumed 5.829s CPU time. Jan 26 17:11:26 volumio-100 systemd[1]: mpd.socket: Deactivated successfully. Jan 26 17:11:26 volumio-100 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 17:11:26 volumio-100 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 17:11:26 volumio-100 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 17:11:26 volumio-100 systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 17:11:26 volumio-100 go-librespot[1580]: time="2026-01-26T17:11:26+01:00" level=debug msg="obtained new client token: AABtyvyu9q9ePmv4vtaHgWguPIomx5T2GfN8Cm7TLxsPhQfa0E2ZkoW9fRgCUEzeWxa685f36OJc98h9zylsfV/Lr+rD1OOE88sj5HDOnxloVpSrFfbldwozWHdrba62xf2t9SoTPZiZ+mCOg4rYmC5snSkzQKaiHm0IF/X6vztovqIQo/1C4Xx6ebap/By6ZDWG6WQcCzXBszYTZf6MtSsX9oXlTwY+bnQzI9dvDXl3ovNRBFtVCf7jIyc=" Jan 26 17:11:27 volumio-100 sudo[1630]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 17:11:27 volumio-100 sudo[1630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 17:11:27 volumio-100 sudo[1630]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:27 volumio-100 volumio[1159]: info: MPD Permissions set Jan 26 17:11:27 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:27 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:27 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:27 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:27 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:27 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:27 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:27 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:27 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 17:11:27 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 17:11:27 volumio-100 volumio[1159]: info: go-librespot daemon successfully initialized Jan 26 17:11:28 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioGetState Jan 26 17:11:28 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:29 volumio-100 volumio[1159]: SPOTIFY: User informations: {"country":"ES","display_name":"Joan Carles","email":"jcilergeta@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/w9ip5xntm3gkpvtznqdo06se5"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/w9ip5xntm3gkpvtznqdo06se5","id":"w9ip5xntm3gkpvtznqdo06se5","images":[],"product":"premium","type":"user","uri":"spotify:user:w9ip5xntm3gkpvtznqdo06se5"} Jan 26 17:11:29 volumio-100 volumio[1159]: info: Spotify Successfully logged in Jan 26 17:11:29 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 17:11:29 volumio-100 volumio[1159]: info: [1769443889394] CoreMusicLibrary::Adding element Spotify Jan 26 17:11:29 volumio-100 volumio[1159]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 17:11:29 volumio-100 volumio[1159]: Cannot find translation for source Spotify Jan 26 17:11:29 volumio-100 go-librespot[1580]: time="2026-01-26T17:11:29+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 26 17:11:29 volumio-100 go-librespot[1580]: time="2026-01-26T17:11:29+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" Jan 26 17:11:29 volumio-100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 17:11:29 volumio-100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 17:11:30 volumio-100 mpd[1632]: 2026-01-26T17:11:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 17:11:30 volumio-100 systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 17:11:30 volumio-100 sudo[1626]: pam_unix(sudo:session): session closed for user root Jan 26 17:11:30 volumio-100 volumio[1159]: error: updateQueue error: null Jan 26 17:11:30 volumio-100 volumio[1159]: info: Initializing connection to go-librespot Websocket Jan 26 17:11:31 volumio-100 volumio[1159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 17:11:31 volumio-100 volumio[1159]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 17:11:31 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 17:11:31 volumio-100 volumio[1159]: info: VolumeController:: Volume=41 Mute =false Jan 26 17:11:31 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioGetState Jan 26 17:11:31 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:31 volumio-100 volumio[1159]: info: CoreStateMachine::pushState Jan 26 17:11:31 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:31 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioPushState Jan 26 17:11:32 volumio-100 volumio[1159]: info: Completed starting Core Plugins Jan 26 17:11:32 volumio-100 volumio[1159]: info: ------------------------------------------- Jan 26 17:11:32 volumio-100 volumio[1159]: info: ----- MyVolumio plugins startup ---- Jan 26 17:11:32 volumio-100 volumio[1159]: info: ------------------------------------------- Jan 26 17:11:32 volumio-100 volumio[1159]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 17:11:33 volumio-100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 26 17:11:33 volumio-100 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 17:11:33 volumio-100 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 17:11:33 volumio-100 go-librespot[1651]: go-librespot daemon starting... Jan 26 17:11:33 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:33+01:00" level=info msg="running go-librespot 0.4.0" Jan 26 17:11:33 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:33+01:00" level=debug msg="app state loaded" Jan 26 17:11:33 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 17:11:34 volumio-100 volumio[1159]: info: Initializing connection to go-librespot Websocket Jan 26 17:11:34 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:34+01:00" level=debug msg="new websocket client" Jan 26 17:11:34 volumio-100 volumio[1159]: info: Connection to go-librespot Websocket established Jan 26 17:11:36 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 26 17:11:36 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:36+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 26 17:11:36 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:36+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 26 17:11:36 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:36+01:00" level=info msg="zeroconf server listening on port 45945" Jan 26 17:11:37 volumio-100 volumio[1159]: info: Getting Spotify volume Jan 26 17:11:37 volumio-100 volumio[1159]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 26 17:11:37 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioGetState Jan 26 17:11:37 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:38 volumio-100 volumio[1159]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Jan 26 17:11:38 volumio-100 volumio[1159]: SPOTIFY: SPOTIFY VOLUME undefined Jan 26 17:11:38 volumio-100 volumio[1159]: SPOTIFY: VOLUMIO VOLUME 41 Jan 26 17:11:38 volumio-100 volumio[1159]: info: Aligning Spotify Volume to Volumio Volume Jan 26 17:11:38 volumio-100 volumio[1159]: info: CoreCommandRouter::volumioGetState Jan 26 17:11:38 volumio-100 volumio[1159]: info: CorePlayQueue::getTrack 0 Jan 26 17:11:38 volumio-100 volumio[1159]: info: Setting Spotify Volume from Volumio: 41 Jan 26 17:11:39 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:39+01:00" level=debug msg="obtained new client token: AABhUTvYsOgZSmfW0/2EF1xbDHfmBsTC8StQD3mPoTDL/P4Fy1H01Re2Fpa760jjeNJmau4BOQ86ZJKIdQiXF0lt4bynvBRL6EthI/rG263UhpvPtxY9kcQGSzMDZA7CVSEHDuI3yZh+iSYNUa1ohBuFeipOXJY4GXeDA3a8mcmwSEtnq0qccwD/cInw6fwbDcP+BiO5z6U6oL19yuwpYYpuevF9K4GmDnsREqAUfu1VIA0FJH/eCIo1" Jan 26 17:11:39 volumio-100 volumio[1159]: SPOTIFY: SETTING SPOTIFY VOLUME 41 Jan 26 17:11:39 volumio-100 volumio[1159]: info: Sending Spotify command with payload to local API: /player/volume Jan 26 17:11:42 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:42+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 26 17:11:42 volumio-100 go-librespot[1657]: time="2026-01-26T17:11:42+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" Jan 26 17:11:42 volumio-100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 17:11:42 volumio-100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 17:11:42 volumio-100 volumio[1159]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jan 26 17:11:42 volumio-100 volumio[1159]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 17:11:42 volumio-100 volumio[1159]: Error: socket hang up Jan 26 17:11:42 volumio-100 volumio[1159]: at connResetException (node:internal/errors:720:14) Jan 26 17:11:42 volumio-100 volumio[1159]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 26 17:11:42 volumio-100 volumio[1159]: at Socket.emit (node:events:526:35) Jan 26 17:11:42 volumio-100 volumio[1159]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 26 17:11:42 volumio-100 volumio[1159]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 26 17:11:42 volumio-100 volumio[1159]: code: 'ECONNRESET', Jan 26 17:11:42 volumio-100 volumio[1159]: response: undefined Jan 26 17:11:42 volumio-100 volumio[1159]: } Jan 26 17:11:42 volumio-100 volumio[1159]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 17:11:45 volumio-100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 26 17:11:45 volumio-100 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 17:11:45 volumio-100 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 17:11:45 volumio-100 go-librespot[1696]: go-librespot daemon starting... Jan 26 17:11:45 volumio-100 go-librespot[1697]: time="2026-01-26T17:11:45+01:00" level=info msg="running go-librespot 0.4.0" Jan 26 17:11:45 volumio-100 go-librespot[1697]: time="2026-01-26T17:11:45+01:00" level=debug msg="app state loaded" Jan 26 17:11:45 volumio-100 go-librespot[1697]: time="2026-01-26T17:11:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 17:11:48 volumio-100 go-librespot[1697]: time="2026-01-26T17:11:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 26 17:11:48 volumio-100 go-librespot[1697]: time="2026-01-26T17:11:48+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 26 17:11:48 volumio-100 go-librespot[1697]: time="2026-01-26T17:11:48+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 26 17:11:48 volumio-100 go-librespot[1697]: time="2026-01-26T17:11:48+01:00" level=info msg="zeroconf server listening on port 32919" Jan 26 17:11:50 volumio-100 sudo[1706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 17:10' Jan 26 17:11:50 volumio-100 sudo[1706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 17:11:51 volumio-100 go-librespot[1697]: time="2026-01-26T17:11:51+01:00" level=debug msg="obtained new client token: AAAJXQtsieOlVPbSChx8IS8d+gMlTkXiFMjRFsmYC6SLzSsX86BvBiwhJ29xVnOq9MzNAqREKavSv3+7bBEHaNrPxYAkwewbkRy/1PlBoUBbXjv5ZLz+bi8DYtHfQtFAxaqArnZrDdHWDJBkBPKbG82FgzPG8xRcM5gW+k+/fn3Su5il8+0TQrHBitvm4HziD5LokX66CLqZRySIO/uNszULwMIlWStm2cr6v3t3Ei5X7zBj9nsw5YWMARM=" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"