-- Logs begin at Thu 2019-02-14 19:11:59 JST, end at Fri 2026-04-10 23:28:39 JST. -- Apr 10 23:27:39 volumio01 fake-hwclock[285]: Fri Apr 10 14:27:39 UTC 2026 Apr 10 23:27:39 volumio01 systemd[1]: Started Restore / save the current clock. Apr 10 23:27:39 volumio01 systemd[1]: Mounted Kernel Configuration File System. Apr 10 23:27:39 volumio01 systemd[1]: Started Apply Kernel Variables. Apr 10 23:27:39 volumio01 systemd[1]: Mounted FUSE Control File System. Apr 10 23:27:39 volumio01 systemd[1]: Starting Helper to synchronize boot up for ifupdown... Apr 10 23:27:39 volumio01 systemd[1]: Starting Create System Users... Apr 10 23:27:39 volumio01 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Apr 10 23:27:39 volumio01 systemd[1]: Starting Load/Save Random Seed... Apr 10 23:27:39 volumio01 systemd[1]: dynamicswap.service: Succeeded. Apr 10 23:27:39 volumio01 systemd[1]: Started Helper to synchronize boot up for ifupdown. Apr 10 23:27:39 volumio01 systemd[1]: Started Load/Save Random Seed. Apr 10 23:27:39 volumio01 systemd[1]: Started Create System Users. Apr 10 23:27:39 volumio01 systemd[1]: Starting Create Static Device Nodes in /dev... Apr 10 23:27:39 volumio01 systemd[1]: Started Create Static Device Nodes in /dev. Apr 10 23:27:39 volumio01 systemd[1]: Starting udev Kernel Device Manager... Apr 10 23:27:39 volumio01 systemd[1]: Reached target Local File Systems (Pre). Apr 10 23:27:39 volumio01 systemd[1]: Mounting /var/spool/cups... Apr 10 23:27:39 volumio01 systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Apr 10 23:27:39 volumio01 systemd[1]: Mounting /var/log... Apr 10 23:27:39 volumio01 systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Apr 10 23:27:39 volumio01 systemd[1]: Mounting /tmp... Apr 10 23:27:39 volumio01 systemd[1]: Mounted /var/spool/cups. Apr 10 23:27:39 volumio01 systemd[1]: Mounted /var/log. Apr 10 23:27:39 volumio01 systemd[1]: Mounted /tmp. Apr 10 23:27:39 volumio01 systemd[1]: Starting Flush Journal to Persistent Storage... Apr 10 23:27:39 volumio01 systemd[1]: Mounting /var/spool/cups/tmp... Apr 10 23:27:39 volumio01 systemd[1]: Mounted /var/spool/cups/tmp. Apr 10 23:27:39 volumio01 systemd-udevd[317]: Network interface NamePolicy= disabled on kernel command line, ignoring. Apr 10 23:27:39 volumio01 systemd-journald[292]: Runtime journal (/run/log/journal/9522fdb065c2fbf4e8ff0b3a65b90e23) is 7.5M, max 30.0M, 22.5M free. Apr 10 23:27:39 volumio01 systemd[1]: Started udev Kernel Device Manager. Apr 10 23:27:39 volumio01 systemd[1]: Starting Show Plymouth Boot Screen... Apr 10 23:27:39 volumio01 systemd[1]: Started Flush Journal to Persistent Storage. Apr 10 23:27:39 volumio01 systemd[1]: plymouth-start.service: Succeeded. Apr 10 23:27:39 volumio01 systemd[1]: Started Show Plymouth Boot Screen. Apr 10 23:27:39 volumio01 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Apr 10 23:27:39 volumio01 systemd[1]: Reached target Local Encrypted Volumes. Apr 10 23:27:39 volumio01 systemd[1]: Reached target Paths. Apr 10 23:27:39 volumio01 systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Apr 10 23:27:39 volumio01 kernel: rpi-gpiomem 3f200000.gpiomem: window base 0x3f200000 size 0x00001000 Apr 10 23:27:39 volumio01 kernel: rpi-gpiomem 3f200000.gpiomem: initialised 1 regions as /dev/gpiomem Apr 10 23:27:39 volumio01 kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Apr 10 23:27:39 volumio01 kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Apr 10 23:27:39 volumio01 kernel: [vc_sm_connected_init]: start Apr 10 23:27:39 volumio01 kernel: [vc_sm_connected_init]: installed successfully Apr 10 23:27:39 volumio01 kernel: mc: Linux media interface: v0.10 Apr 10 23:27:39 volumio01 kernel: videodev: Linux video capture interface: v2.00 Apr 10 23:27:39 volumio01 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Apr 10 23:27:39 volumio01 kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Apr 10 23:27:39 volumio01 kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Apr 10 23:27:39 volumio01 systemd[1]: Found device /dev/disk/by-uuid/EAAE-0197. Apr 10 23:27:39 volumio01 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Apr 10 23:27:39 volumio01 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Apr 10 23:27:39 volumio01 kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Apr 10 23:27:39 volumio01 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Apr 10 23:27:39 volumio01 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Apr 10 23:27:39 volumio01 kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Apr 10 23:27:39 volumio01 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Apr 10 23:27:39 volumio01 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Apr 10 23:27:39 volumio01 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Apr 10 23:27:39 volumio01 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Apr 10 23:27:39 volumio01 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Apr 10 23:27:39 volumio01 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Apr 10 23:27:39 volumio01 kernel: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Apr 10 23:27:39 volumio01 kernel: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Apr 10 23:27:39 volumio01 kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Apr 10 23:27:39 volumio01 kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Apr 10 23:27:39 volumio01 kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Apr 10 23:27:40 volumio01 kernel: Bluetooth: Core ver 2.22 Apr 10 23:27:40 volumio01 kernel: NET: Registered PF_BLUETOOTH protocol family Apr 10 23:27:40 volumio01 kernel: Bluetooth: HCI device and connection manager initialized Apr 10 23:27:40 volumio01 kernel: Bluetooth: HCI socket layer initialized Apr 10 23:27:40 volumio01 kernel: Bluetooth: L2CAP socket layer initialized Apr 10 23:27:40 volumio01 kernel: Bluetooth: SCO socket layer initialized Apr 10 23:27:40 volumio01 kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Apr 10 23:27:40 volumio01 kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Apr 10 23:27:40 volumio01 kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Apr 10 23:27:40 volumio01 kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Apr 10 23:27:40 volumio01 kernel: Bluetooth: HCI UART driver ver 2.3 Apr 10 23:27:40 volumio01 kernel: Bluetooth: HCI UART protocol H4 registered Apr 10 23:27:40 volumio01 kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Apr 10 23:27:40 volumio01 kernel: Bluetooth: HCI UART protocol Broadcom registered Apr 10 23:27:40 volumio01 kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Apr 10 23:27:40 volumio01 kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Apr 10 23:27:40 volumio01 kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Apr 10 23:27:40 volumio01 kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Apr 10 23:27:40 volumio01 kernel: usbcore: registered new interface driver brcmfmac Apr 10 23:27:40 volumio01 kernel: uart-pl011 3f201000.serial: no DMA platform data Apr 10 23:27:40 volumio01 systemd[1]: Starting File System Check on /dev/disk/by-uuid/EAAE-0197... Apr 10 23:27:40 volumio01 systemd-udevd[333]: Using default interface naming scheme 'v240'. Apr 10 23:27:40 volumio01 systemd-udevd[333]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 10 23:27:40 volumio01 systemd[1]: Started File System Check Daemon to report status. Apr 10 23:27:40 volumio01 systemd-udevd[327]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 10 23:27:40 volumio01 systemd-fsck[390]: fsck.fat 4.1 (2017-01-24) Apr 10 23:27:40 volumio01 systemd-fsck[390]: Unexpected long filename sequence number (2 vs. expected 1). Apr 10 23:27:40 volumio01 systemd-fsck[390]: It could be that just the number is wrong Apr 10 23:27:40 volumio01 systemd-fsck[390]: if "network-confi" seems to match "g". Apr 10 23:27:40 volumio01 systemd-fsck[390]: Not auto-correcting this. Apr 10 23:27:40 volumio01 systemd-fsck[390]: /dev/mmcblk0p1: 409 files, 41771/46774 clusters Apr 10 23:27:40 volumio01 systemd[1]: Started File System Check on /dev/disk/by-uuid/EAAE-0197. Apr 10 23:27:40 volumio01 kernel: brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob available (err=-2) Apr 10 23:27:40 volumio01 kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 Apr 10 23:27:40 volumio01 kernel: Bluetooth: hci0: BCM: chip id 107 Apr 10 23:27:40 volumio01 kernel: Bluetooth: hci0: BCM: features 0x2f Apr 10 23:27:40 volumio01 kernel: Bluetooth: hci0: BCM4345C0 Apr 10 23:27:40 volumio01 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Apr 10 23:27:40 volumio01 kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Apr 10 23:27:40 volumio01 kernel: usbcore: registered new interface driver snd-usb-audio Apr 10 23:27:40 volumio01 systemd-udevd[326]: Using default interface naming scheme 'v240'. Apr 10 23:27:40 volumio01 systemd-udevd[326]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 10 23:27:41 volumio01 kernel: Bluetooth: hci0: BCM: features 0x2f Apr 10 23:27:41 volumio01 kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Apr 10 23:27:41 volumio01 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Apr 10 23:27:41 volumio01 kernel: Bluetooth: hci0: BCM: Using default device address (43:45:c0:00:1f:ac) Apr 10 23:27:41 volumio01 kernel: alsactl[443]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set Apr 10 23:27:41 volumio01 systemd-udevd[329]: Process '/bin/bash -c '/usr/local/bin/volumio scanaudioinputs'' failed with exit code 7. Apr 10 23:27:41 volumio01 systemd-udevd[324]: Process '/bin/bash -c '/usr/local/bin/volumio usbattach'' failed with exit code 7. Apr 10 23:27:41 volumio01 systemd[1]: Condition check resulted in 7800 being skipped. Apr 10 23:27:41 volumio01 systemd[1]: Condition check resulted in /sys/subsystem/net/devices/wlan0 being skipped. Apr 10 23:27:41 volumio01 systemd[1]: Created slice system-bthelper.slice. Apr 10 23:27:41 volumio01 systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Apr 10 23:27:41 volumio01 systemd[1]: Starting Show Plymouth Boot Screen... Apr 10 23:27:41 volumio01 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Apr 10 23:27:41 volumio01 systemd[1]: Condition check resulted in Huge Pages File System being skipped. Apr 10 23:27:41 volumio01 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Apr 10 23:27:41 volumio01 systemd[1]: Mounting /boot... Apr 10 23:27:41 volumio01 systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 10 23:27:41 volumio01 systemd[1]: plymouth-start.service: Succeeded. Apr 10 23:27:41 volumio01 systemd[1]: Started Show Plymouth Boot Screen. Apr 10 23:27:41 volumio01 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Apr 10 23:27:41 volumio01 systemd[1]: Mounted /boot. Apr 10 23:27:41 volumio01 systemd[1]: Reached target Local File Systems. Apr 10 23:27:41 volumio01 systemd[1]: Starting Raise network interfaces... Apr 10 23:27:41 volumio01 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Apr 10 23:27:41 volumio01 systemd[1]: Started ifup for eth0. Apr 10 23:27:41 volumio01 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Apr 10 23:27:41 volumio01 systemd[1]: Starting Preprocess NFS configuration... Apr 10 23:27:41 volumio01 systemd[1]: Started ifup for wlan0. Apr 10 23:27:41 volumio01 systemd[1]: Starting Create Volatile Files and Directories... Apr 10 23:27:41 volumio01 systemd[1]: Started Load/Save RF Kill Switch Status. Apr 10 23:27:41 volumio01 systemd[1]: plymouth-read-write.service: Succeeded. Apr 10 23:27:41 volumio01 systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Apr 10 23:27:41 volumio01 systemd[1]: Received SIGRTMIN+20 from PID 178 (plymouthd). Apr 10 23:27:41 volumio01 systemd[1]: nfs-config.service: Succeeded. Apr 10 23:27:41 volumio01 systemd[1]: Started Preprocess NFS configuration. Apr 10 23:27:41 volumio01 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Apr 10 23:27:41 volumio01 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Apr 10 23:27:41 volumio01 systemd[1]: Reached target NFS client services. Apr 10 23:27:41 volumio01 kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211 Apr 10 23:27:41 volumio01 systemd[1]: Started Create Volatile Files and Directories. Apr 10 23:27:41 volumio01 systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Apr 10 23:27:41 volumio01 systemd[1]: Starting RPC bind portmap service... Apr 10 23:27:41 volumio01 systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Apr 10 23:27:41 volumio01 systemd[1]: Starting Update UTMP about System Boot/Shutdown... Apr 10 23:27:42 volumio01 systemd[1]: Started RPC bind portmap service. Apr 10 23:27:42 volumio01 systemd[1]: Reached target RPC Port Mapper. Apr 10 23:27:42 volumio01 systemd[1]: Reached target Remote File Systems (Pre). Apr 10 23:27:42 volumio01 systemd[1]: Reached target Remote File Systems. Apr 10 23:27:42 volumio01 systemd[1]: Started Update UTMP about System Boot/Shutdown. Apr 10 23:27:42 volumio01 systemd[1]: Reached target System Initialization. Apr 10 23:27:42 volumio01 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 10 23:27:42 volumio01 systemd[1]: Listening on triggerhappy.socket. Apr 10 23:27:42 volumio01 systemd[1]: Listening on D-Bus System Message Bus Socket. Apr 10 23:27:42 volumio01 systemd[1]: Started Daily apt download activities. Apr 10 23:27:42 volumio01 systemd[1]: Started Daily apt upgrade and clean activities. Apr 10 23:27:42 volumio01 systemd[1]: Started Daily Cleanup of Temporary Directories. Apr 10 23:27:42 volumio01 systemd[1]: Reached target Timers. Apr 10 23:27:42 volumio01 systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Apr 10 23:27:42 volumio01 systemd[1]: Reached target Sockets. Apr 10 23:27:42 volumio01 systemd[1]: Reached target Basic System. Apr 10 23:27:42 volumio01 kernel: 8021q: 802.1Q VLAN Support v1.8 Apr 10 23:27:42 volumio01 systemd[1]: Starting triggerhappy global hotkey daemon... Apr 10 23:27:42 volumio01 systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Apr 10 23:27:42 volumio01 systemd[1]: Started D-Bus System Message Bus. Apr 10 23:27:42 volumio01 systemd[1]: Starting WPA supplicant... Apr 10 23:27:42 volumio01 systemd[1]: Starting Login Service... Apr 10 23:27:42 volumio01 thd[545]: Unable to parse trigger line: Apr 10 23:27:42 volumio01 thd[545]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Apr 10 23:27:42 volumio01 thd[545]: Unable to parse trigger line: Apr 10 23:27:42 volumio01 thd[545]: Found socket passed from systemd Apr 10 23:27:42 volumio01 systemd[1]: Started volumio-remote-updater.service. Apr 10 23:27:42 volumio01 systemd[1]: Started Volumio Log Rotation Service. Apr 10 23:27:42 volumio01 systemd[1]: Starting Configure Bluetooth Modems connected by UART... Apr 10 23:27:42 volumio01 systemd[1]: Started Manage Sound Card State (restore and store). Apr 10 23:27:42 volumio01 systemd[1]: Starting Save/Restore Sound Card State... Apr 10 23:27:42 volumio01 systemd[1]: Started Volumio Iptables Module. Apr 10 23:27:42 volumio01 systemd[1]: Starting dhcpcd on all interfaces... Apr 10 23:27:42 volumio01 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Apr 10 23:27:42 volumio01 alsactl[573]: alsactl 1.1.8 daemon started Apr 10 23:27:42 volumio01 systemd[1]: Started UPnP Renderer front-end to MPD. Apr 10 23:27:42 volumio01 systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Apr 10 23:27:42 volumio01 systemd[1]: Starting Wireless Services... Apr 10 23:27:42 volumio01 systemd[1]: Starting Volumio Time Update Utility... Apr 10 23:27:42 volumio01 systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Apr 10 23:27:42 volumio01 systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Apr 10 23:27:42 volumio01 systemd[1]: Started triggerhappy global hotkey daemon. Apr 10 23:27:42 volumio01 dhcpcd[578]: Not running dhcpcd because /etc/network/interfaces Apr 10 23:27:42 volumio01 dhcpcd[578]: defines some interfaces that will use a Apr 10 23:27:42 volumio01 dhcpcd[578]: DHCP client or static address Apr 10 23:27:42 volumio01 systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Apr 10 23:27:42 volumio01 systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Apr 10 23:27:42 volumio01 systemd[1]: Failed to start dhcpcd on all interfaces. Apr 10 23:27:42 volumio01 volumio-time-update[585]: volumio-time-update-util: Fetching time from Volumio... Apr 10 23:27:42 volumio01 sh[468]: eth0: waiting for carrier Apr 10 23:27:42 volumio01 kernel: lan78xx 1-1.1.1:1.0 eth0: kevent 4 may have been dropped Apr 10 23:27:42 volumio01 kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 23:27:42 volumio01 dhcpcd[517]: eth0: waiting for carrier Apr 10 23:27:42 volumio01 systemd-logind[568]: New seat seat0. Apr 10 23:27:42 volumio01 sh[468]: eth0: carrier acquired Apr 10 23:27:42 volumio01 dhcpcd[517]: eth0: carrier acquired Apr 10 23:27:42 volumio01 kernel: lan78xx 1-1.1.1:1.0 eth0: Link is Up - 1Gbps/Full - flow control rx/tx Apr 10 23:27:42 volumio01 sh[468]: DUID 00:01:00:01:2d:4b:cc:69:b8:27:eb:fa:fe:0b Apr 10 23:27:42 volumio01 sh[468]: eth0: IAID eb:6c:03:48 Apr 10 23:27:42 volumio01 dhcpcd[517]: DUID 00:01:00:01:2d:4b:cc:69:b8:27:eb:fa:fe:0b Apr 10 23:27:42 volumio01 dhcpcd[517]: eth0: IAID eb:6c:03:48 Apr 10 23:27:42 volumio01 sh[468]: eth0: adding address fe80::b8b4:c0ef:70c6:649 Apr 10 23:27:42 volumio01 sh[468]: ipv6_addaddr1: Permission denied Apr 10 23:27:42 volumio01 dhcpcd[517]: eth0: adding address fe80::b8b4:c0ef:70c6:649 Apr 10 23:27:42 volumio01 dhcpcd[517]: ipv6_addaddr1: Permission denied Apr 10 23:27:42 volumio01 volumio-remote-updater[570]: Error: No active session Apr 10 23:27:42 volumio01 volumio-remote-updater[570]: [2026-04-10 23:27:42] [info] asio async_connect error: system:111 (Connection refused) Apr 10 23:27:42 volumio01 volumio-remote-updater[570]: [2026-04-10 23:27:42] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 10 23:27:42 volumio01 volumio-remote-updater[570]: [2026-04-10 23:27:42] [error] handle_connect error: Underlying Transport Error Apr 10 23:27:42 volumio01 avahi-daemon[591]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Apr 10 23:27:42 volumio01 avahi-daemon[591]: Successfully dropped root privileges. Apr 10 23:27:42 volumio01 avahi-daemon[591]: avahi-daemon 0.7 starting up. Apr 10 23:27:43 volumio01 volumio-time-update[585]: volumio-time-update-util: Date not found in response Apr 10 23:27:43 volumio01 volumio-time-update[585]: volumio-time-update-util: Retrying in 5 seconds... Apr 10 23:27:43 volumio01 dbus-daemon[563]: [system] Successfully activated service 'org.freedesktop.systemd1' Apr 10 23:27:43 volumio01 systemd[1]: Started Login Service. Apr 10 23:27:43 volumio01 systemd[1]: hciuart.service: Succeeded. Apr 10 23:27:43 volumio01 systemd[1]: Started Configure Bluetooth Modems connected by UART. Apr 10 23:27:43 volumio01 avahi-daemon[591]: Successfully called chroot(). Apr 10 23:27:43 volumio01 systemd[1]: Started Save/Restore Sound Card State. Apr 10 23:27:43 volumio01 avahi-daemon[591]: Successfully dropped remaining capabilities. Apr 10 23:27:43 volumio01 wpa_supplicant[567]: Successfully initialized wpa_supplicant Apr 10 23:27:43 volumio01 avahi-daemon[591]: Loading service file /services/volumio.service. Apr 10 23:27:43 volumio01 avahi-daemon[591]: Network interface enumeration completed. Apr 10 23:27:43 volumio01 avahi-daemon[591]: Server startup complete. Host name is volumio01.local. Local service cookie is 3514380894. Apr 10 23:27:43 volumio01 avahi-daemon[591]: Service "Volumio01" (/services/volumio.service) successfully established. Apr 10 23:27:43 volumio01 systemd[1]: Started WPA supplicant. Apr 10 23:27:43 volumio01 volumio[580]: Could not open config: /tmp/upmpdcli.conf Apr 10 23:27:43 volumio01 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 10 23:27:43 volumio01 dhcpcd[517]: eth0: soliciting a DHCP lease Apr 10 23:27:43 volumio01 sh[468]: eth0: soliciting a DHCP lease Apr 10 23:27:43 volumio01 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 10 23:27:43 volumio01 sh[471]: wlan0=wlan0 Apr 10 23:27:43 volumio01 systemd[1]: Started Avahi mDNS/DNS-SD Stack. Apr 10 23:27:43 volumio01 systemd[1]: Reached target Sound Card. Apr 10 23:27:43 volumio01 systemd[1]: Starting Raspberry Pi bluetooth helper... Apr 10 23:27:43 volumio01 systemd[1]: Started Raise network interfaces. Apr 10 23:27:43 volumio01 systemd[1]: Reached target Network. Apr 10 23:27:43 volumio01 systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Apr 10 23:27:43 volumio01 systemd[1]: Reached target Network is Online. Apr 10 23:27:43 volumio01 systemd[1]: Starting LSB: Brings up/down network automatically... Apr 10 23:27:43 volumio01 systemd[1]: Starting /etc/rc.local Compatibility... Apr 10 23:27:43 volumio01 systemd[1]: Starting Samba NMB Daemon... Apr 10 23:27:43 volumio01 haveged[509]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Apr 10 23:27:43 volumio01 haveged[509]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Apr 10 23:27:43 volumio01 haveged[509]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00036 Apr 10 23:27:43 volumio01 haveged[509]: haveged: fills: 0, generated: 0 Apr 10 23:27:43 volumio01 systemd[1]: Starting Permit User Sessions... Apr 10 23:27:43 volumio01 systemd[1]: Starting Network Time Service... Apr 10 23:27:43 volumio01 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 10 23:27:43 volumio01 systemd[1]: Started /etc/rc.local Compatibility. Apr 10 23:27:43 volumio01 sh[468]: eth0: soliciting an IPv6 router Apr 10 23:27:43 volumio01 dhcpcd[517]: eth0: soliciting an IPv6 router Apr 10 23:27:43 volumio01 systemd[1]: Started Permit User Sessions. Apr 10 23:27:43 volumio01 systemd[1]: Starting Terminate Plymouth Boot Screen... Apr 10 23:27:43 volumio01 bthelper[665]: Raspberry Pi BDADDR already set Apr 10 23:27:43 volumio01 systemd[1]: Starting Hold until boot process finishes up... Apr 10 23:27:43 volumio01 systemd[1]: Started Raspberry Pi bluetooth helper. Apr 10 23:27:43 volumio01 systemd[1]: Received SIGRTMIN+21 from PID 178 (plymouthd). Apr 10 23:27:43 volumio01 systemd[1]: iptables.service: Succeeded. Apr 10 23:27:43 volumio01 systemd[1]: Starting Bluetooth service... Apr 10 23:27:43 volumio01 systemd[1]: plymouth-quit.service: Succeeded. Apr 10 23:27:43 volumio01 systemd[1]: Started Terminate Plymouth Boot Screen. Apr 10 23:27:43 volumio01 systemd[1]: plymouth-quit-wait.service: Succeeded. Apr 10 23:27:43 volumio01 systemd[1]: Started Hold until boot process finishes up. Apr 10 23:27:43 volumio01 systemd[1]: Received SIGRTMIN+21 from PID 178 (n/a). Apr 10 23:27:43 volumio01 ifplugd(eth0)[727]: ifplugd 0.28 initializing. Apr 10 23:27:43 volumio01 ifplugd(eth0)[727]: Using interface eth0/B8:27:EB:6C:03:48 with driver (version: 6.6.62-v7+) Apr 10 23:27:43 volumio01 ifplugd(eth0)[727]: Using detection mode: SIOCETHTOOL Apr 10 23:27:43 volumio01 ifplugd(eth0)[727]: Initialization complete, link beat detected. Apr 10 23:27:43 volumio01 systemd[1]: Started Getty on tty1. Apr 10 23:27:43 volumio01 systemd[1]: Reached target Login Prompts. Apr 10 23:27:44 volumio01 loadcpufreq[587]: Loading cpufreq kernel modules...done (none). Apr 10 23:27:44 volumio01 systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Apr 10 23:27:44 volumio01 systemd[1]: Starting LSB: set CPUFreq kernel parameters... Apr 10 23:27:44 volumio01 ifplugd(eth0)[727]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Apr 10 23:27:44 volumio01 bluetoothd[701]: Bluetooth daemon 5.83 Apr 10 23:27:44 volumio01 ntpd[676]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 10 23:27:44 volumio01 ntpd[676]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Apr 10 23:27:44 volumio01 systemd[1]: Started Network Time Service. Apr 10 23:27:44 volumio01 ntpd[742]: proto: precision = 0.625 usec (-21) Apr 10 23:27:44 volumio01 ntpd[742]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 10 23:27:44 volumio01 ntpd[742]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 10 23:27:44 volumio01 ntpd[742]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 469 days ago Apr 10 23:27:44 volumio01 ntpd[742]: Listen and drop on 0 v6wildcard [::]:123 Apr 10 23:27:44 volumio01 ntpd[742]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 10 23:27:44 volumio01 ntpd[742]: Listen normally on 2 lo 127.0.0.1:123 Apr 10 23:27:44 volumio01 ntpd[742]: Listening on routing socket on fd #19 for interface updates Apr 10 23:27:44 volumio01 ntpd[742]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 10 23:27:44 volumio01 ntpd[742]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 10 23:27:44 volumio01 bluetoothd[701]: src/main.c:check_options() Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Apr 10 23:27:44 volumio01 ifplugd(eth0)[727]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Apr 10 23:27:44 volumio01 systemd[1]: Started Bluetooth service. Apr 10 23:27:44 volumio01 systemd[1]: Reached target Bluetooth. Apr 10 23:27:44 volumio01 bluetoothd[701]: Starting SDP server Apr 10 23:27:44 volumio01 bluetoothd[701]: Excluding (cli) hostname Apr 10 23:27:44 volumio01 bluetoothd[701]: Excluding (cli) scanparam Apr 10 23:27:44 volumio01 bluetoothd[701]: Excluding (cli) battery Apr 10 23:27:44 volumio01 cpufrequtils[730]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Apr 10 23:27:44 volumio01 systemd[1]: Started LSB: set CPUFreq kernel parameters. Apr 10 23:27:44 volumio01 sh[468]: eth0: offered 10.5.60.80 from 10.5.60.1 `ix2215-1' Apr 10 23:27:44 volumio01 sh[468]: eth0: probing address 10.5.60.80/24 Apr 10 23:27:44 volumio01 dhcpcd[517]: eth0: offered 10.5.60.80 from 10.5.60.1 `ix2215-1' Apr 10 23:27:44 volumio01 dhcpcd[517]: eth0: probing address 10.5.60.80/24 Apr 10 23:27:44 volumio01 bluetoothd[701]: Bluetooth management interface 1.22 initialized Apr 10 23:27:44 volumio01 bluetoothd[701]: Battery Provider Manager created Apr 10 23:27:44 volumio01 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Apr 10 23:27:44 volumio01 kernel: Bluetooth: BNEP filters: protocol multicast Apr 10 23:27:44 volumio01 kernel: Bluetooth: BNEP socket layer initialized Apr 10 23:27:44 volumio01 kernel: Bluetooth: MGMT ver 1.22 Apr 10 23:27:44 volumio01 kernel: NET: Registered PF_ALG protocol family Apr 10 23:27:44 volumio01 kernel: cryptd: max_cpu_qlen set to 1000 Apr 10 23:27:44 volumio01 bluetoothd[701]: Failed to set privacy: Rejected (0x0b) Apr 10 23:27:45 volumio01 nmbd[683]: [2026/04/10 23:27:45.136769, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Apr 10 23:27:45 volumio01 nmbd[683]: started asyncdns process 774 Apr 10 23:27:45 volumio01 nmbd[683]: [2026/04/10 23:27:45.138875, 0] ../lib/util/become_daemon.c:149(daemon_status) Apr 10 23:27:45 volumio01 nmbd[683]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Apr 10 23:27:45 volumio01 nmbd[683]: [2026/04/10 23:27:45.139073, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Apr 10 23:27:45 volumio01 nmbd[683]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Apr 10 23:27:45 volumio01 ntpd[742]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 10 23:27:45 volumio01 wireless.js[582]: Cleaning previous... Apr 10 23:27:45 volumio01 sudo[782]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 10 23:27:45 volumio01 sudo[782]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:45 volumio01 sudo[782]: pam_unix(sudo:session): session closed for user root Apr 10 23:27:45 volumio01 sudo[784]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 10 23:27:45 volumio01 sudo[784]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:46 volumio01 ntpd[742]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 10 23:27:46 volumio01 sudo[784]: pam_unix(sudo:session): session closed for user root Apr 10 23:27:46 volumio01 wireless.js[582]: Stopped aP Apr 10 23:27:46 volumio01 sudo[791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 10 23:27:46 volumio01 sudo[791]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:46 volumio01 sudo[791]: pam_unix(sudo:session): session closed for user root Apr 10 23:27:46 volumio01 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 10 23:27:46 volumio01 sudo[793]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Apr 10 23:27:46 volumio01 sudo[793]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:46 volumio01 sudo[793]: pam_unix(sudo:session): session closed for user root Apr 10 23:27:46 volumio01 sudo[800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 10 23:27:46 volumio01 sudo[800]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:46 volumio01 sudo[800]: pam_unix(sudo:session): session closed for user root Apr 10 23:27:46 volumio01 sudo[802]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Apr 10 23:27:46 volumio01 sudo[802]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:46 volumio01 systemd[1]: systemd-rfkill.service: Succeeded. Apr 10 23:27:47 volumio01 ntpd[742]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 10 23:27:47 volumio01 volumio-remote-updater[570]: [2026-04-10 23:27:47] [info] asio async_connect error: system:111 (Connection refused) Apr 10 23:27:47 volumio01 volumio-remote-updater[570]: [2026-04-10 23:27:47] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 10 23:27:47 volumio01 volumio-remote-updater[570]: [2026-04-10 23:27:47] [error] handle_connect error: Underlying Transport Error Apr 10 23:27:48 volumio01 volumio-time-update[585]: volumio-time-update-util: Fetching time from Volumio... Apr 10 23:27:48 volumio01 volumio-time-update[585]: volumio-time-update-util: Date not found in response Apr 10 23:27:48 volumio01 volumio-time-update[585]: volumio-time-update-util: Retrying in 5 seconds... Apr 10 23:27:48 volumio01 ntpd[742]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 10 23:27:48 volumio01 bluetoothd[701]: src/adv_monitor.c:btd_adv_monitor_power_down() Unexpected NULL btd_adv_monitor_manager object upon power down Apr 10 23:27:48 volumio01 bthelper[665]: [NEW] Media /org/bluez/hci0 Apr 10 23:27:48 volumio01 bthelper[665]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Apr 10 23:27:48 volumio01 bthelper[665]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Apr 10 23:27:48 volumio01 bthelper[665]: hci0 class of device changed: 0x000000 Apr 10 23:27:48 volumio01 bthelper[665]: hci0 new_settings: bondable ssp br/edr le secure-conn Apr 10 23:27:48 volumio01 bthelper[665]: [CHG] Controller B8:27:EB:C6:A9:E2 PowerState: on-disabling Apr 10 23:27:48 volumio01 bthelper[665]: Changing power off succeeded Apr 10 23:27:48 volumio01 bthelper[665]: [CHG] Controller B8:27:EB:C6:A9:E2 PowerState: off Apr 10 23:27:48 volumio01 bthelper[665]: [CHG] Controller B8:27:EB:C6:A9:E2 Powered: no Apr 10 23:27:48 volumio01 bthelper[665]: [CHG] Controller B8:27:EB:C6:A9:E2 Discovering: no Apr 10 23:27:48 volumio01 bthelper[665]: [CHG] Controller B8:27:EB:C6:A9:E2 Class: 0x00000000 (0) Apr 10 23:27:48 volumio01 bthelper[665]: [NEW] Media /org/bluez/hci0 Apr 10 23:27:48 volumio01 bthelper[665]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Apr 10 23:27:48 volumio01 bthelper[665]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Apr 10 23:27:48 volumio01 bthelper[665]: [CHG] Controller B8:27:EB:C6:A9:E2 PowerState: off-enabling Apr 10 23:27:48 volumio01 bthelper[665]: hci0 class of device changed: 0x00041c Apr 10 23:27:48 volumio01 bthelper[665]: [CHG] Controller B8:27:EB:C6:A9:E2 Class: 0x0000041c (1052) Apr 10 23:27:48 volumio01 bthelper[665]: hci0 new_settings: powered bondable ssp br/edr le secure-conn Apr 10 23:27:48 volumio01 bthelper[665]: Changing power on succeeded Apr 10 23:27:48 volumio01 sudo[802]: pam_unix(sudo:session): session closed for user root Apr 10 23:27:48 volumio01 wireless.js[582]: SETTING APPROPRIATE REG DOMAIN: JP Apr 10 23:27:48 volumio01 sudo[813]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 10 23:27:48 volumio01 sudo[813]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:48 volumio01 sudo[813]: pam_unix(sudo:session): session closed for user root Apr 10 23:27:48 volumio01 sudo[815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set JP Apr 10 23:27:48 volumio01 sudo[815]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:48 volumio01 sudo[815]: pam_unix(sudo:session): session closed for user root Apr 10 23:27:48 volumio01 wireless.js[582]: SUCCESSFULLY SET NEW REGDOMAIN: JP Apr 10 23:27:49 volumio01 sudo[822]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 10 23:27:49 volumio01 sudo[822]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:49 volumio01 sudo[822]: pam_unix(sudo:session): session closed for user root Apr 10 23:27:49 volumio01 sudo[824]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 10 23:27:49 volumio01 sudo[824]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:49 volumio01 sudo[824]: pam_unix(sudo:session): session closed for user root Apr 10 23:27:49 volumio01 wireless.js[582]: Hotspot is disabled, not starting it Apr 10 23:27:49 volumio01 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 10 23:27:49 volumio01 systemd[1]: wireless.service: Succeeded. Apr 10 23:27:49 volumio01 systemd[1]: Started Wireless Services. Apr 10 23:27:49 volumio01 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 10 23:27:49 volumio01 systemd[1]: Started Volumio Backend Module. Apr 10 23:27:49 volumio01 systemd[1]: Started Volumio Cpu Tweaker. Apr 10 23:27:49 volumio01 volumio-cpu-tweak[831]: Setting RT Priority for mpd Apr 10 23:27:49 volumio01 volumio-cpu-tweak[831]: pid 35's current scheduling policy: SCHED_OTHER Apr 10 23:27:49 volumio01 volumio-cpu-tweak[831]: pid 35's current scheduling priority: 0 Apr 10 23:27:49 volumio01 volumio-cpu-tweak[831]: Setting MPD Affinity Apr 10 23:27:49 volumio01 volumio-cpu-tweak[831]: pid 3's current affinity mask: f Apr 10 23:27:49 volumio01 volumio-cpu-tweak[831]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Apr 10 23:27:49 volumio01 volumio-cpu-tweak[831]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Apr 10 23:27:49 volumio01 sh[468]: eth0: leased 10.5.60.80 for 14400 seconds Apr 10 23:27:49 volumio01 dhcpcd[517]: eth0: leased 10.5.60.80 for 14400 seconds Apr 10 23:27:49 volumio01 sh[468]: eth0: adding route to 10.5.60.0/24 Apr 10 23:27:49 volumio01 sh[468]: eth0: adding default route via 10.5.60.1 Apr 10 23:27:49 volumio01 dhcpcd[517]: eth0: adding route to 10.5.60.0/24 Apr 10 23:27:49 volumio01 dhcpcd[517]: eth0: adding default route via 10.5.60.1 Apr 10 23:27:49 volumio01 avahi-daemon[591]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.5.60.80. Apr 10 23:27:49 volumio01 avahi-daemon[591]: New relevant interface eth0.IPv4 for mDNS. Apr 10 23:27:49 volumio01 avahi-daemon[591]: Registering new address record for 10.5.60.80 on eth0.IPv4. Apr 10 23:27:49 volumio01 systemd[1]: volumio_cpu_tweak.service: Succeeded. Apr 10 23:27:49 volumio01 sh[468]: forked to background, child pid 867 Apr 10 23:27:49 volumio01 dhcpcd[517]: forked to background, child pid 867 Apr 10 23:27:50 volumio01 nmbd[683]: [2026/04/10 23:27:50.191638, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 10 23:27:50 volumio01 nmbd[683]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Apr 10 23:27:50 volumio01 systemd[1]: Started Samba NMB Daemon. Apr 10 23:27:50 volumio01 nmbd[683]: [2026/04/10 23:27:50.214671, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Apr 10 23:27:50 volumio01 nmbd[683]: query_name_response: Multiple (2) responses received for a query on subnet 10.5.60.80 for name WORKGROUP<1d>. Apr 10 23:27:50 volumio01 nmbd[683]: This response was from IP 10.5.60.31, reporting an IP address of 10.5.60.31. Apr 10 23:27:50 volumio01 systemd[1]: Starting Samba Winbind Daemon... Apr 10 23:27:50 volumio01 ifplugd(eth0)[727]: client: ifup: interface eth0 already configured Apr 10 23:27:50 volumio01 sh[468]: eth0=eth0 Apr 10 23:27:50 volumio01 ifplugd(eth0)[727]: Program executed successfully. Apr 10 23:27:50 volumio01 ifplugd[668]: Network Interface Plugging Daemon...start eth0...done. Apr 10 23:27:50 volumio01 systemd[1]: Started LSB: Brings up/down network automatically. Apr 10 23:27:50 volumio01 winbindd[889]: [2026/04/10 23:27:50.625506, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 10 23:27:50 volumio01 winbindd[889]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 10 23:27:51 volumio01 ntpd[742]: Listen normally on 3 eth0 10.5.60.80:123 Apr 10 23:27:51 volumio01 ntpd[742]: new interface(s) found: waking up resolver Apr 10 23:27:51 volumio01 winbindd[889]: [2026/04/10 23:27:51.485876, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 10 23:27:51 volumio01 systemd[1]: Started Samba Winbind Daemon. Apr 10 23:27:51 volumio01 winbindd[889]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 10 23:27:51 volumio01 systemd[1]: Starting Samba SMB Daemon... Apr 10 23:27:53 volumio01 volumio-time-update[585]: volumio-time-update-util: Fetching time from Volumio... Apr 10 23:27:53 volumio01 smbd[898]: [2026/04/10 23:27:53.611344, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 10 23:27:53 volumio01 systemd[1]: Started Samba SMB Daemon. Apr 10 23:27:53 volumio01 smbd[898]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 10 23:27:53 volumio01 volumio-time-update[585]: volumio-time-update-util: Setting system time to: 2026-04-10 23:28:14 Apr 10 23:27:53 volumio01 sudo[911]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2026-04-10 23:28:14 Apr 10 23:27:53 volumio01 sudo[911]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:27:53 volumio01 dbus-daemon[563]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.9' (uid=0 pid=912 comm="timedatectl set-time 2026-04-10 23:28:14 ") Apr 10 23:27:54 volumio01 systemd[1]: Starting Time & Date Service... Apr 10 23:27:54 volumio01 dbus-daemon[563]: [system] Successfully activated service 'org.freedesktop.timedate1' Apr 10 23:27:54 volumio01 systemd[1]: Started Time & Date Service. Apr 10 23:28:14 volumio01 systemd-timedated[913]: Changed local time to Fri Apr 10 23:28:14 2026 Apr 10 23:28:14 volumio01 sudo[911]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:14 volumio01 volumio-time-update[585]: volumio-time-update-util: System time updated successfully. Apr 10 23:28:14 volumio01 systemd[1]: Started Volumio Time Update Utility. Apr 10 23:28:14 volumio01 systemd[1]: Reached target Multi-User System. Apr 10 23:28:14 volumio01 systemd[1]: Reached target Graphical Interface. Apr 10 23:28:14 volumio01 systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 10 23:28:14 volumio01 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 10 23:28:14 volumio01 systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 10 23:28:14 volumio01 systemd[1]: Startup finished in 13.444s (kernel) + 16.752s (userspace) = 30.197s. Apr 10 23:28:14 volumio01 volumio[830]: info: ------------------------------------------- Apr 10 23:28:14 volumio01 volumio[830]: info: ----- Volumio3 ---- Apr 10 23:28:14 volumio01 volumio[830]: info: ------------------------------------------- Apr 10 23:28:14 volumio01 volumio[830]: info: ----- System startup ---- Apr 10 23:28:14 volumio01 volumio[830]: info: ------------------------------------------- Apr 10 23:28:15 volumio01 volumio-remote-updater[570]: [2026-04-10 23:28:15] [connect] Successful connection Apr 10 23:28:15 volumio01 volumio[830]: info: MYVOLUMIO Environment detected Apr 10 23:28:15 volumio01 volumio[830]: info: Plugin folders cleanup Apr 10 23:28:15 volumio01 volumio[830]: info: Scanning into folder /volumio/app/plugins/ Apr 10 23:28:15 volumio01 volumio[830]: info: Scanning category audio_interface Apr 10 23:28:15 volumio01 volumio[830]: info: Scanning category miscellanea Apr 10 23:28:15 volumio01 volumio[830]: info: Scanning category music_service Apr 10 23:28:15 volumio01 volumio[830]: info: Scanning category plugins.json Apr 10 23:28:15 volumio01 volumio[830]: info: Scanning category system_controller Apr 10 23:28:15 volumio01 volumio[830]: info: Scanning category user_interface Apr 10 23:28:15 volumio01 volumio[830]: info: Scanning into folder /data/plugins/ Apr 10 23:28:15 volumio01 volumio[830]: info: Scanning category music_service Apr 10 23:28:15 volumio01 volumio[830]: info: Plugin folders cleanup completed Apr 10 23:28:15 volumio01 volumio[830]: info: ------------------------------------------- Apr 10 23:28:15 volumio01 volumio[830]: info: ----- Core plugins startup ---- Apr 10 23:28:15 volumio01 volumio[830]: info: ------------------------------------------- Apr 10 23:28:15 volumio01 volumio[830]: info: Loading plugins from folder /volumio/app/plugins/ Apr 10 23:28:15 volumio01 volumio[830]: info: Adding plugin upnp to MyMusic Plugins Apr 10 23:28:15 volumio01 volumio[830]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 10 23:28:15 volumio01 volumio[830]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 10 23:28:15 volumio01 volumio[830]: info: Loading plugins from folder /data/plugins/ Apr 10 23:28:15 volumio01 volumio[830]: info: Loading plugin "system"... Apr 10 23:28:15 volumio01 volumio[830]: info: Loading plugin "appearance"... Apr 10 23:28:17 volumio01 volumio[830]: info: Loading plugin "network"... Apr 10 23:28:17 volumio01 volumio[830]: info: Refreshing Cached IP Addresses Apr 10 23:28:17 volumio01 sudo[929]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 10 23:28:17 volumio01 sudo[929]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:17 volumio01 sudo[929]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:17 volumio01 sudo[931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 10 23:28:17 volumio01 sudo[931]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:17 volumio01 sudo[931]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:17 volumio01 volumio[830]: info: Loading plugin "services"... Apr 10 23:28:17 volumio01 volumio[830]: info: Loading plugin "volumio5onboarding"... Apr 10 23:28:17 volumio01 sudo[940]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 10 23:28:17 volumio01 sudo[940]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:17 volumio01 volumio[830]: info: Loading plugin "alsa_controller"... Apr 10 23:28:17 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 10 23:28:17 volumio01 volumio[830]: info: Loading plugin "wizard"... Apr 10 23:28:17 volumio01 volumio[830]: info: Loading plugin "networkfs"... Apr 10 23:28:17 volumio01 volumio[830]: info: Starting Udev Watcher for removable devices Apr 10 23:28:17 volumio01 sudo[955]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=styleray,password=S@itoh01,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //10.5.60.26/media /mnt/NAS/media Apr 10 23:28:17 volumio01 sudo[955]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:17 volumio01 volumio[830]: info: Ignoring mount for partition: boot Apr 10 23:28:17 volumio01 volumio[830]: info: Ignoring mount for partition: volumio Apr 10 23:28:17 volumio01 volumio[830]: info: Ignoring mount for partition: volumio_data Apr 10 23:28:17 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 10 23:28:17 volumio01 volumio[830]: info: Loading plugin "volumio_command_line_client"... Apr 10 23:28:17 volumio01 volumio[830]: info: Loading plugin "upnp"... Apr 10 23:28:17 volumio01 volumio[830]: info: [1775831297701] Starting Upmpd Daemon Apr 10 23:28:17 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 10 23:28:17 volumio01 volumio[830]: info: Loading plugin "my_music"... Apr 10 23:28:17 volumio01 volumio[830]: info: Loading plugin "mpd"... Apr 10 23:28:17 volumio01 kernel: Key type cifs.spnego registered Apr 10 23:28:17 volumio01 kernel: Key type cifs.idmap registered Apr 10 23:28:17 volumio01 kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Apr 10 23:28:17 volumio01 kernel: CIFS: Attempting to mount //10.5.60.26/media Apr 10 23:28:18 volumio01 sudo[955]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:18 volumio01 volumio[830]: info: Loading plugin "upnp_browser"... Apr 10 23:28:18 volumio01 volumio[830]: info: Starting UPNP Browser Apr 10 23:28:18 volumio01 volumio[830]: info: Loading plugin "alarm-clock"... Apr 10 23:28:18 volumio01 volumio[830]: info: Loading plugin "airplay_emulation"... Apr 10 23:28:18 volumio01 volumio[830]: info: Starting Shairport Sync Apr 10 23:28:18 volumio01 volumio[830]: info: Loading plugin "last_100"... Apr 10 23:28:18 volumio01 volumio[830]: info: Loading plugin "webradio"... Apr 10 23:28:19 volumio01 volumio[830]: info: Loading plugin "i2s_dacs"... Apr 10 23:28:19 volumio01 volumio[830]: info: I2S DAC not set, start Auto-detection Apr 10 23:28:19 volumio01 volumio[830]: info: Loading plugin "volumiodiscovery"... Apr 10 23:28:19 volumio01 volumio[830]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 10 23:28:19 volumio01 volumio[830]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 10 23:28:19 volumio01 volumio[830]: *** WARNING *** For more information see Apr 10 23:28:19 volumio01 volumio[830]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 10 23:28:19 volumio01 volumio[830]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 10 23:28:19 volumio01 volumio[830]: *** WARNING *** For more information see Apr 10 23:28:19 volumio01 node[830]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 10 23:28:19 volumio01 node[830]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 10 23:28:19 volumio01 node[830]: *** WARNING *** For more information see Apr 10 23:28:19 volumio01 node[830]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 10 23:28:19 volumio01 node[830]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 10 23:28:19 volumio01 node[830]: *** WARNING *** For more information see Apr 10 23:28:19 volumio01 volumio[830]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 10 23:28:19 volumio01 volumio[830]: info: Discovery: Started advertising with name: Volumio01 Apr 10 23:28:19 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 10 23:28:19 volumio01 volumio[830]: info: Loading plugin "spop"... Apr 10 23:28:19 volumio01 sudo[940]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:21 volumio01 volumio[830]: info: Loading plugin "youtube2"... Apr 10 23:28:23 volumio01 volumio[830]: info: Loading plugin "ytcr"... Apr 10 23:28:26 volumio01 volumio[830]: info: Loading plugin "outputs"... Apr 10 23:28:26 volumio01 volumio[830]: info: Loading plugin "albumart"... Apr 10 23:28:26 volumio01 volumio[830]: info: Plugin example_plugin is not enabled Apr 10 23:28:26 volumio01 volumio[830]: info: Loading plugin "inputs"... Apr 10 23:28:26 volumio01 volumio[830]: info: Loading plugin "updater_comm"... Apr 10 23:28:27 volumio01 volumio[830]: info: Plugin mpdemulation is not enabled Apr 10 23:28:27 volumio01 volumio[830]: info: Loading plugin "rest_api"... Apr 10 23:28:27 volumio01 volumio[830]: info: Loading plugin "websocket"... Apr 10 23:28:27 volumio01 volumio[830]: info: Starting Socket.io Server version 2.3.0 Apr 10 23:28:27 volumio01 volumio[830]: info: Loading i18n strings for locale ja Apr 10 23:28:27 volumio01 volumio[830]: Updating browse sources language Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 23:28:27 volumio01 volumio[830]: Forking 3 albumart workers Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::initPlayerControls Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 10 23:28:27 volumio01 volumio[830]: Express server listening on port 3000 Apr 10 23:28:27 volumio01 volumio[830]: [Metrics] WebUI: 13s 904.52ms Apr 10 23:28:27 volumio01 volumio[830]: info: CoreStateMachine::resetVolumioState Apr 10 23:28:27 volumio01 volumio[830]: info: CoreStateMachine::getcurrentVolume Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::volumioRetrievevolume Apr 10 23:28:27 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 23:28:27 volumio01 sudo[1045]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 10 23:28:27 volumio01 sudo[1045]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:27 volumio01 sudo[1045]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:27 volumio01 sudo[1047]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 10 23:28:27 volumio01 sudo[1047]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:27 volumio01 sudo[1047]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:27 volumio01 volumio[830]: info: Volumio Network Manager: Network status updated: 1 Apr 10 23:28:28 volumio01 volumio[830]: verbose: New Socket.io Connection to 10.5.60.80 from 10.5.60.112 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Apr 10 23:28:28 volumio01 volumio[830]: verbose: New Socket.io Connection to 10.5.60.80 from 10.5.60.112 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Apr 10 23:28:28 volumio01 volumio[830]: info: CoreStateMachine::pushState Apr 10 23:28:28 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioPushState Apr 10 23:28:28 volumio01 volumio[830]: info: CoreStateMachine::updateTrackBlock Apr 10 23:28:28 volumio01 volumio[830]: info: CorePlayQueue::getTrackBlock Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioRetrievevolume Apr 10 23:28:28 volumio01 volumio[830]: info: Reloading queue from file Apr 10 23:28:28 volumio01 volumio[830]: verbose: New Socket.io Connection to 10.5.60.80 from 10.5.60.112 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Apr 10 23:28:28 volumio01 volumio[830]: info: CoreStateMachine::setRepeat null single undefined Apr 10 23:28:28 volumio01 volumio[830]: info: CoreStateMachine::pushState Apr 10 23:28:28 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioPushState Apr 10 23:28:28 volumio01 volumio[830]: info: CoreStateMachine::setRandom null Apr 10 23:28:28 volumio01 volumio[830]: info: CoreStateMachine::pushState Apr 10 23:28:28 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioPushState Apr 10 23:28:28 volumio01 volumio[830]: info: Setting Device type: Raspberry PI Apr 10 23:28:28 volumio01 volumio[830]: info: CoreStateMachine::pushState Apr 10 23:28:28 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioPushState Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetVisibleSources Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetState Apr 10 23:28:28 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetState Apr 10 23:28:28 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 10 23:28:28 volumio01 volumio[830]: info: Received Get System Info Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 23:28:28 volumio01 volumio[830]: info: Discovery: Getting this device information Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetState Apr 10 23:28:28 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetState Apr 10 23:28:28 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:28 volumio01 volumio[830]: info: Listing playlists Apr 10 23:28:28 volumio01 volumio[830]: Starting albumart workers Apr 10 23:28:28 volumio01 volumio[830]: Starting albumart workers Apr 10 23:28:28 volumio01 volumio[830]: info: Discovery: adding 2613c7dc-8f99-4a69-a128-4ea2942f9e1c Apr 10 23:28:28 volumio01 volumio[830]: info: Discovery: Found device Volumio01 Apr 10 23:28:28 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetState Apr 10 23:28:28 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:28 volumio01 volumio[830]: Starting albumart workers Apr 10 23:28:28 volumio01 sudo[1062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 10 23:28:28 volumio01 sudo[1062]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:28 volumio01 systemd[1]: Started UPnP Renderer front-end to MPD. Apr 10 23:28:28 volumio01 sudo[1062]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:30 volumio01 volumio-remote-updater[570]: [2026-04-10 23:28:30] [connect] Successful connection Apr 10 23:28:30 volumio01 systemd[1]: systemd-fsckd.service: Succeeded. Apr 10 23:28:31 volumio01 volumio[830]: info: Upmpdcli Daemon Started Apr 10 23:28:31 volumio01 volumio[830]: info: Completed loading Core Plugins Apr 10 23:28:31 volumio01 volumio[830]: info: Preparing to generate the ALSA configuration file Apr 10 23:28:31 volumio01 volumio[830]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 10 23:28:31 volumio01 volumio-remote-updater[570]: [2026-04-10 23:28:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1775831310 101 Apr 10 23:28:31 volumio01 volumio[830]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 4 Apr 10 23:28:31 volumio01 volumio[830]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 10 23:28:31 volumio01 volumio[830]: info: Reading ALSA contributions from plugins. Apr 10 23:28:31 volumio01 volumio[830]: info: Asound.conf file unchanged, so no further update is needed Apr 10 23:28:31 volumio01 volumio[830]: info: Output device has changed, restarting MPD Apr 10 23:28:31 volumio01 sudo[1090]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 10 23:28:31 volumio01 volumio[830]: info: Output device has changed, restarting Shairport Sync Apr 10 23:28:31 volumio01 sudo[1090]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 23:28:31 volumio01 sudo[1090]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:31 volumio01 sudo[1092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 10 23:28:31 volumio01 sudo[1092]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:31 volumio01 volumio[830]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 10 23:28:31 volumio01 volumio[830]: info: ___________ START PLUGINS ___________ Apr 10 23:28:31 volumio01 volumio[830]: info: ControllerMpd::onStart: Initializing MPD Apr 10 23:28:31 volumio01 volumio[830]: info: Creating MPD Configuration file Apr 10 23:28:31 volumio01 sudo[1100]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 10 23:28:31 volumio01 sudo[1100]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:31 volumio01 systemd[1]: Listening on mpd.socket. Apr 10 23:28:31 volumio01 sudo[1102]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 10 23:28:31 volumio01 systemd[1]: Starting Music Player Daemon... Apr 10 23:28:31 volumio01 sudo[1102]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:31 volumio01 sudo[1102]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 10 23:28:31 volumio01 volumio[830]: info: [1775831311433] CoreMusicLibrary::Adding element DLNAサーバー Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 23:28:31 volumio01 sudo[1107]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 10 23:28:31 volumio01 sudo[1107]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:31 volumio01 volumio[830]: info: UPNP Browser: Client initialized successfully Apr 10 23:28:31 volumio01 systemd[1]: Started Volumio5 Onboarding Server. Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 23:28:31 volumio01 sudo[1100]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:31 volumio01 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Apr 10 23:28:31 volumio01 systemd[1]: mpd.service: Succeeded. Apr 10 23:28:31 volumio01 systemd[1]: Stopped Music Player Daemon. Apr 10 23:28:31 volumio01 systemd[1]: Starting Music Player Daemon... Apr 10 23:28:31 volumio01 volumio[830]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 23:28:31 volumio01 volumio[830]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 10 23:28:31 volumio01 volumio[830]: info: [1775831311579] CoreMusicLibrary::Adding element Last_100 Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 10 23:28:31 volumio01 volumio[830]: info: [1775831311583] CoreMusicLibrary::Adding element Webradio Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 10 23:28:31 volumio01 volumio[830]: info: Initializing BBC Radios Apr 10 23:28:31 volumio01 sudo[1113]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 10 23:28:31 volumio01 sudo[1113]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:31 volumio01 sudo[1113]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 10 23:28:31 volumio01 sudo[1113]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 23:28:31 volumio01 volumio[830]: info: Creating Spotify config file Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 10 23:28:31 volumio01 volumio[830]: info: [1775831311763] CoreMusicLibrary::Adding element YouTube2 Apr 10 23:28:31 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 23:28:31 volumio01 volumio[830]: Cannot find translation for source YouTube2 Apr 10 23:28:31 volumio01 volumio[830]: info: Volumio Calling Home Apr 10 23:28:31 volumio01 volumio[830]: info: MPD Permissions set Apr 10 23:28:32 volumio01 volumio[830]: info: MPD Permissions set Apr 10 23:28:32 volumio01 volumio[830]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 10 23:28:32 volumio01 volumio[830]: info: Spotify config file written Apr 10 23:28:32 volumio01 volumio[830]: info: No need to fix Spotify hosts Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 sudo[1138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 10 23:28:32 volumio01 sudo[1138]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 10 23:28:32 volumio01 volumio5-onboarding[1109]: time=2026-04-10T23:28:32.191+09:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Apr 10 23:28:32 volumio01 systemd[1]: Started go-librespot Daemon. Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetState Apr 10 23:28:32 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:32 volumio01 sudo[1138]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:32 volumio01 go-librespot[1148]: go-librespot daemon starting... Apr 10 23:28:32 volumio01 volumio[830]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 6 Apr 10 23:28:32 volumio01 volumio[830]: info: Starting Shairport Sync Apr 10 23:28:32 volumio01 volumio[830]: info: Starting Shairport Sync Apr 10 23:28:32 volumio01 volumio[830]: info: Starting Shairport Sync Apr 10 23:28:32 volumio01 sudo[1156]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 10 23:28:32 volumio01 sudo[1156]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:32 volumio01 sudo[1158]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 10 23:28:32 volumio01 sudo[1158]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:32 volumio01 sudo[1160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 10 23:28:32 volumio01 sudo[1160]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 10 23:28:32 volumio01 volumio[830]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 6 Apr 10 23:28:32 volumio01 volumio[830]: info: Received Get System Info Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 23:28:32 volumio01 volumio[830]: info: Discovery: Getting this device information Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetState Apr 10 23:28:32 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 23:28:32 volumio01 volumio[830]: info: Volumio called home Apr 10 23:28:32 volumio01 volumio5-onboarding[1109]: time=2026-04-10T23:28:32.480+09:00 level=INFO msg="system info for c9e89cc74762a37dce45fd0074772595" deviceName=Volumio01 deviceVariant=volumio deviceModel= softwareVersion=3.908 Apr 10 23:28:32 volumio01 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 10 23:28:32 volumio01 systemd[1]: shairport-sync.service: Succeeded. Apr 10 23:28:32 volumio01 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 10 23:28:32 volumio01 volumio[830]: info: Received Get System Info Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 23:28:32 volumio01 volumio[830]: info: Discovery: Getting this device information Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetState Apr 10 23:28:32 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 10 23:28:32 volumio01 volumio5-onboarding[1109]: time=2026-04-10T23:28:32.538+09:00 level=INFO msg="enabling local network discovery" Apr 10 23:28:32 volumio01 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 10 23:28:32 volumio01 volumio5-onboarding[1109]: time=2026-04-10T23:28:32.576+09:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 10 23:28:32 volumio01 sudo[1156]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:32 volumio01 volumio[830]: info: Received Get System Info Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 23:28:32 volumio01 volumio[830]: info: Discovery: Getting this device information Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetState Apr 10 23:28:32 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:32 volumio01 sudo[1158]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:32 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 23:28:32 volumio01 volumio[830]: info: Shairport-Sync Started Apr 10 23:28:32 volumio01 volumio[830]: Error adding Membership: Error: addMembership EINVAL Apr 10 23:28:32 volumio01 volumio[830]: info: Shairport-Sync Started Apr 10 23:28:32 volumio01 sudo[1160]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:32 volumio01 volumio[830]: info: Shairport-Sync Started Apr 10 23:28:32 volumio01 volumio-remote-updater[570]: No test mode Apr 10 23:28:32 volumio01 volumio-remote-updater[570]: No alpha test mode Apr 10 23:28:33 volumio01 volumio[830]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 10 23:28:33 volumio01 volumio[830]: SPOTIFY: BQAFCiBtg3WkHQAP_etkv0jtlYb1ldcXwUyKtTR66YfCBRXmOoqBa1bhhytmbrurCJuOp6ivYV3qK7UoEAGmd9IYPb0n-_QKxjYQOt9eboWmxMUuPtWZBzUD7SYpcAVSY-GdOJyWASAFgf6NyBZVgdRZ6t65aaBFNPne3t-X2fvSXO-F5yyliAW9VvjENnK0QK14CQ1LeH_KS-KzauKAfAQZH3NPe8j4l390QLMocU1kGx1X_5y-4SfcVY9cs391A9D16HSwf-9k8xuGOhmGKtMGfgK7diuuEf0NcRoAG7WaZnDM0Bsew2WYeAEdcg Apr 10 23:28:33 volumio01 volumio[830]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 10 23:28:33 volumio01 volumio[830]: info: New Spotify access token = BQAFCiBtg3WkHQAP_etkv0jtlYb1ldcXwUyKtTR66YfCBRXmOoqBa1bhhytmbrurCJuOp6ivYV3qK7UoEAGmd9IYPb0n-_QKxjYQOt9eboWmxMUuPtWZBzUD7SYpcAVSY-GdOJyWASAFgf6NyBZVgdRZ6t65aaBFNPne3t-X2fvSXO-F5yyliAW9VvjENnK0QK14CQ1LeH_KS-KzauKAfAQZH3NPe8j4l390QLMocU1kGx1X_5y-4SfcVY9cs391A9D16HSwf-9k8xuGOhmGKtMGfgK7diuuEf0NcRoAG7WaZnDM0Bsew2WYeAEdcg Apr 10 23:28:33 volumio01 volumio[830]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 10 23:28:33 volumio01 volumio[830]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

\n
    \n
  • Fix for BLE notification issues
    • \n
  • Fix for mDNS/BCT
    • \n
\n

NEW ADDITIONS

\n
    \n
  • Update Tidal SDK
    • \n
  • Update Qobuz Connect SDK
    • \n
\n","title":"Update v3.912","updateavailable":true} Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=info msg="running go-librespot 0.4.0" Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=debug msg="app state loaded" Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 10 23:28:33 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 10 23:28:33 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 23:28:33 volumio01 volumio5-onboarding[1109]: time=2026-04-10T23:28:33.254+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Apr 10 23:28:33 volumio01 volumio5-onboarding[1109]: time=2026-04-10T23:28:33.255+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Apr 10 23:28:33 volumio01 volumio5-onboarding[1109]: time=2026-04-10T23:28:33.256+09:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Apr 10 23:28:33 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 23:28:33 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 23:28:33 volumio01 volumio[830]: SPOTIFY: User informations: {"country":"JP","display_name":"TKYJP1 第2管制C (TKY_JP1_CNT)","email":"tky.jp1.cnt@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31w7vn52yfc6q5e3d7snir7ysqxu"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31w7vn52yfc6q5e3d7snir7ysqxu","id":"31w7vn52yfc6q5e3d7snir7ysqxu","images":[],"product":"premium","type":"user","uri":"spotify:user:31w7vn52yfc6q5e3d7snir7ysqxu"} Apr 10 23:28:33 volumio01 volumio[830]: info: Spotify Successfully logged in Apr 10 23:28:33 volumio01 volumio[830]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 10 23:28:33 volumio01 volumio[830]: info: [1775831313320] CoreMusicLibrary::Adding element Spotify Apr 10 23:28:33 volumio01 volumio[830]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 10 23:28:33 volumio01 volumio[830]: Cannot find translation for source YouTube2 Apr 10 23:28:33 volumio01 volumio[830]: Cannot find translation for source Spotify Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=info msg="zeroconf server listening on port 40993" Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=debug msg="obtained new client token: AACRcnVmbEunMWOHjfQgxtqAp5STIHb1q+h/n8So6LskWnXSWm3cPRodvLbyiIDr47P4KJpu4AKA9T7uT+QeBkHkE43VY8fhoR+uLixaQvplpOB/XGPAvs8rVrpckQl05U2vsiVyo6zdsSjTUnjfnTxk7oS+3PPS4A88/prcWtXrv9VH/uvkxQVUvIgq+fW3RhTi6X7jHPVTxc1CF3WK+1geYiuEDgZr+VVytiU0rAiksM2HDRkqY7H0qg==" Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=debug msg="completed keyexchange" Apr 10 23:28:33 volumio01 go-librespot[1148]: time="2026-04-10T23:28:33+09:00" level=debug msg="completed challenge" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=info msg="authenticated AP" username="31************************xu" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=info msg="authenticated Login5" username="31************************xu" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=debug msg="initializing zeroconf session" username="31************************xu" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=debug msg="dealer connection opened" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=trace msg="starting accesspoint recv loop" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=trace msg="starting dealer recv loop" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=trace msg="received accesspoint ping" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=trace msg="received accesspoint pong ack" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=debug msg="received connection id: ZGViNDFjMzEtYWFl...MEVENTg3NjQwNg==" Apr 10 23:28:34 volumio01 go-librespot[1148]: time="2026-04-10T23:28:34+09:00" level=debug msg="put connect state because NEW_DEVICE" Apr 10 23:28:35 volumio01 mpd[1120]: Apr 10 23:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 10 23:28:35 volumio01 systemd[1]: Started Music Player Daemon. Apr 10 23:28:35 volumio01 volumio[830]: Upnp client error: Error: This socket has been ended by the other party Apr 10 23:28:35 volumio01 sudo[1107]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:35 volumio01 sudo[1092]: pam_unix(sudo:session): session closed for user root Apr 10 23:28:35 volumio01 volumio[830]: info: go-librespot daemon successfully initialized Apr 10 23:28:35 volumio01 volumio[830]: error: MPD error: The expression evaluated to a falsy value: Apr 10 23:28:35 volumio01 volumio[830]: assert.ok(self.idling) Apr 10 23:28:35 volumio01 volumio[830]: error: The expression evaluated to a falsy value: Apr 10 23:28:35 volumio01 volumio[830]: assert.ok(self.idling) Apr 10 23:28:35 volumio01 volumio[830]: info: MPD running with PID1120 Apr 10 23:28:35 volumio01 volumio[830]: ,establishing connection Apr 10 23:28:35 volumio01 volumio[830]: error: updateQueue error: null Apr 10 23:28:35 volumio01 volumio[830]: error: updateQueue error: null Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=debug msg="handling transfer player command from e6d15002b93cee7f05f0c2c0a7d65ae456ccc5e5" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=debug msg="resolved context of track" uri="spotify:album:0zaK1X6b8qfc3O8JDqPjZQ" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=trace msg="fetched new page 0 with 9 items (list: 9)" uri="spotify:album:0zaK1X6b8qfc3O8JDqPjZQ" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=debug msg="loading track (paused: true, position: 60161ms)" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=trace msg="emitting websocket event: will_play" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=debug msg="selected format OGG_VORBIS_320 (1eee2b9a2363cb7fdbf78f004836c8202918d3ff)" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=debug msg="requested aes key for file 1eee2b9a2363cb7fdbf78f004836c8202918d3ff, gid: 695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1440" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=trace msg="found 2 cdn urls" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1174" Apr 10 23:28:37 volumio01 go-librespot[1148]: time="2026-04-10T23:28:37+09:00" level=debug msg="fetched first chunk of 21, total size is 10533549 bytes" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="fetched chunk 7/20, size: 524288" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="fetched chunk 4/20, size: 524288" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=trace msg="seek to 60161ms (diff: 49ms, samples: 2653100, bytes: 2459926)" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="created new output device" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=info msg="loaded track \"TRUTH\" (paused: true, position: 60161ms, duration: 259665ms, prefetched: false)" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="fetched chunk 5/20, size: 524288" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="fetched chunk 6/20, size: 524288" uri="spotify:track:695jTUtLNuJRLjIDPmF0Hn" Apr 10 23:28:38 volumio01 volumio[830]: info: Initializing connection to go-librespot Websocket Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="new websocket client" Apr 10 23:28:38 volumio01 volumio[830]: info: Connection to go-librespot Websocket established Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=trace msg="emitting websocket event: metadata" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=trace msg="emitting websocket event: active" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="sending successful reply for dealer request" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 10 23:28:38 volumio01 volumio[830]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:695jTUtLNuJRLjIDPmF0Hn","name":"TRUTH","artist_names":["T-SQUARE"],"album_name":"TRUTH","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02146959718287f09b3f07f30c","position":60161,"duration":259665,"release_date":"year:1987 month:4 day:1","track_number":5,"disc_number":1}} Apr 10 23:28:38 volumio01 volumio[830]: SPOTIFY: received: {"type":"active","data":null} Apr 10 23:28:38 volumio01 volumio[830]: info: Aligning Spotify Volume to Volumio Volume Apr 10 23:28:38 volumio01 volumio[830]: info: CoreCommandRouter::volumioGetState Apr 10 23:28:38 volumio01 volumio[830]: info: CorePlayQueue::getTrack 0 Apr 10 23:28:38 volumio01 volumio[830]: info: Setting Spotify Volume from Volumio: 21 Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 10 23:28:38 volumio01 go-librespot[1148]: time="2026-04-10T23:28:38+09:00" level=trace msg="emitting websocket event: paused" Apr 10 23:28:38 volumio01 volumio[830]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:0zaK1X6b8qfc3O8JDqPjZQ","uri":"spotify:track:695jTUtLNuJRLjIDPmF0Hn","play_origin":"album"}} Apr 10 23:28:38 volumio01 volumio[1064]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 10 23:28:38 volumio01 volumio[830]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 10 23:28:38 volumio01 volumio[830]: TypeError: Cannot read property 'service' of undefined Apr 10 23:28:38 volumio01 volumio[830]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Apr 10 23:28:38 volumio01 volumio[830]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Apr 10 23:28:38 volumio01 volumio[830]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Apr 10 23:28:38 volumio01 volumio[830]: at WebSocket.emit (events.js:315:20) Apr 10 23:28:38 volumio01 volumio[830]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Apr 10 23:28:38 volumio01 volumio[830]: at Receiver.emit (events.js:315:20) Apr 10 23:28:38 volumio01 volumio[830]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Apr 10 23:28:38 volumio01 volumio[830]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Apr 10 23:28:38 volumio01 volumio[830]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Apr 10 23:28:38 volumio01 volumio[830]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Apr 10 23:28:38 volumio01 volumio[830]: at writeOrBuffer (internal/streams/writable.js:358:12) Apr 10 23:28:38 volumio01 volumio[830]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Apr 10 23:28:38 volumio01 volumio[830]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Apr 10 23:28:38 volumio01 volumio[830]: at Socket.emit (events.js:315:20) Apr 10 23:28:38 volumio01 volumio[830]: at addChunk (internal/streams/readable.js:309:12) Apr 10 23:28:38 volumio01 volumio[830]: at readableAddChunk (internal/streams/readable.js:284:9) Apr 10 23:28:38 volumio01 volumio[830]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 10 23:28:39 volumio01 sudo[1220]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-10 23:27 Apr 10 23:28:39 volumio01 sudo[1220]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Feb 2026 01:46:18 PM CET" VOLUMIO_VERSION="3.908" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3e9dbaf8f44792d26e97456a18f12823"