-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Tue 2025-11-18 11:40:23 UTC. -- Nov 18 11:39:27 cafemusic fake-hwclock[268]: Tue Nov 18 11:39:27 UTC 2025 Nov 18 11:39:27 cafemusic systemd[1]: Mounted RPC Pipe File System. Nov 18 11:39:27 cafemusic systemd[1]: Mounted POSIX Message Queue File System. Nov 18 11:39:27 cafemusic systemd[1]: Started Restore / save the current clock. Nov 18 11:39:27 cafemusic systemd[1]: Started Load Kernel Modules. Nov 18 11:39:27 cafemusic systemd[1]: Mounted Kernel Debug File System. Nov 18 11:39:27 cafemusic systemd[1]: Started Create list of required static device nodes for the current kernel. Nov 18 11:39:27 cafemusic systemd[1]: Mounting FUSE Control File System... Nov 18 11:39:27 cafemusic systemd[1]: Mounting Kernel Configuration File System... Nov 18 11:39:27 cafemusic systemd[1]: Starting Apply Kernel Variables... Nov 18 11:39:27 cafemusic systemd[1]: Mounted FUSE Control File System. Nov 18 11:39:27 cafemusic systemd[1]: Mounted Kernel Configuration File System. Nov 18 11:39:27 cafemusic systemd[1]: Started Remount Root and Kernel File Systems. Nov 18 11:39:27 cafemusic systemd[1]: Starting Load/Save Random Seed... Nov 18 11:39:27 cafemusic systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Nov 18 11:39:27 cafemusic systemd[1]: Starting Create System Users... Nov 18 11:39:27 cafemusic systemd[1]: Started Apply Kernel Variables. Nov 18 11:39:27 cafemusic volumio[266]: 512 MB or less RAM Detected, need to enable swap Nov 18 11:39:27 cafemusic systemd[1]: Started Load/Save Random Seed. Nov 18 11:39:27 cafemusic systemd[1]: Started udev Coldplug all Devices. Nov 18 11:39:27 cafemusic systemd[1]: Starting Helper to synchronize boot up for ifupdown... Nov 18 11:39:27 cafemusic systemd[1]: Started Create System Users. Nov 18 11:39:27 cafemusic systemd[1]: Starting Create Static Device Nodes in /dev... Nov 18 11:39:27 cafemusic volumio[266]: Enabling Swap Nov 18 11:39:27 cafemusic kernel: ext4 filesystem being mounted at /swap supports timestamps until 2038-01-19 (0x7fffffff) Nov 18 11:39:27 cafemusic systemd[1]: Started Create Static Device Nodes in /dev. Nov 18 11:39:27 cafemusic volumio[266]: Setting swappiness to 40 Nov 18 11:39:27 cafemusic kernel: Adding 524236k swap on /swap/swapfile. Priority:-2 extents:12 across:575480k SS Nov 18 11:39:27 cafemusic systemd[1]: Starting udev Kernel Device Manager... Nov 18 11:39:27 cafemusic systemd[1]: Reached target Local File Systems (Pre). Nov 18 11:39:27 cafemusic systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Nov 18 11:39:27 cafemusic systemd[1]: Mounting /var/log... Nov 18 11:39:27 cafemusic systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Nov 18 11:39:27 cafemusic systemd[1]: Mounting /tmp... Nov 18 11:39:27 cafemusic systemd[1]: Mounting /var/spool/cups... Nov 18 11:39:27 cafemusic volumio[266]: vm.swappiness = 40 Nov 18 11:39:27 cafemusic systemd-udevd[304]: Network interface NamePolicy= disabled on kernel command line, ignoring. Nov 18 11:39:27 cafemusic systemd[1]: dynamicswap.service: Succeeded. Nov 18 11:39:27 cafemusic systemd[1]: Mounted /var/log. Nov 18 11:39:27 cafemusic systemd[1]: Mounted /tmp. Nov 18 11:39:27 cafemusic systemd[1]: Mounted /var/spool/cups. Nov 18 11:39:27 cafemusic systemd[1]: Mounting /var/spool/cups/tmp... Nov 18 11:39:27 cafemusic systemd[1]: Starting Flush Journal to Persistent Storage... Nov 18 11:39:27 cafemusic systemd[1]: Mounted /var/spool/cups/tmp. Nov 18 11:39:27 cafemusic systemd[1]: Started udev Kernel Device Manager. Nov 18 11:39:27 cafemusic systemd[1]: Starting Show Plymouth Boot Screen... Nov 18 11:39:27 cafemusic systemd-journald[273]: Runtime journal (/run/log/journal/26288ad12cf0817baa21aee262cc2d39) is 7.5M, max 30.0M, 22.5M free. Nov 18 11:39:27 cafemusic systemd[1]: Started Flush Journal to Persistent Storage. Nov 18 11:39:27 cafemusic systemd[1]: plymouth-start.service: Succeeded. Nov 18 11:39:27 cafemusic systemd[1]: Started Show Plymouth Boot Screen. Nov 18 11:39:27 cafemusic systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Nov 18 11:39:27 cafemusic systemd[1]: Reached target Local Encrypted Volumes. Nov 18 11:39:27 cafemusic systemd[1]: Reached target Paths. Nov 18 11:39:27 cafemusic systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Nov 18 11:39:27 cafemusic kernel: rpi-gpiomem 3f200000.gpiomem: window base 0x3f200000 size 0x00001000 Nov 18 11:39:27 cafemusic kernel: rpi-gpiomem 3f200000.gpiomem: initialised 1 regions as /dev/gpiomem Nov 18 11:39:27 cafemusic kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Nov 18 11:39:27 cafemusic kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Nov 18 11:39:27 cafemusic kernel: [vc_sm_connected_init]: start Nov 18 11:39:27 cafemusic kernel: [vc_sm_connected_init]: installed successfully Nov 18 11:39:27 cafemusic kernel: mc: Linux media interface: v0.10 Nov 18 11:39:28 cafemusic kernel: videodev: Linux video capture interface: v2.00 Nov 18 11:39:28 cafemusic kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 18 11:39:28 cafemusic kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Nov 18 11:39:28 cafemusic kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Nov 18 11:39:28 cafemusic kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Nov 18 11:39:28 cafemusic kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Nov 18 11:39:28 cafemusic kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Nov 18 11:39:28 cafemusic kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Nov 18 11:39:28 cafemusic kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Nov 18 11:39:28 cafemusic kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Nov 18 11:39:28 cafemusic kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Nov 18 11:39:28 cafemusic kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Nov 18 11:39:28 cafemusic kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Nov 18 11:39:28 cafemusic kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Nov 18 11:39:28 cafemusic kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Nov 18 11:39:28 cafemusic kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Nov 18 11:39:28 cafemusic kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Nov 18 11:39:28 cafemusic kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Nov 18 11:39:28 cafemusic systemd[1]: Found device /dev/disk/by-uuid/DC0C-AF04. Nov 18 11:39:28 cafemusic kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Nov 18 11:39:28 cafemusic kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Nov 18 11:39:28 cafemusic kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Nov 18 11:39:28 cafemusic kernel: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Nov 18 11:39:28 cafemusic kernel: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Nov 18 11:39:28 cafemusic kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Nov 18 11:39:28 cafemusic kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Nov 18 11:39:28 cafemusic systemd[1]: Starting File System Check on /dev/disk/by-uuid/DC0C-AF04... Nov 18 11:39:28 cafemusic kernel: Bluetooth: Core ver 2.22 Nov 18 11:39:28 cafemusic kernel: NET: Registered PF_BLUETOOTH protocol family Nov 18 11:39:28 cafemusic kernel: Bluetooth: HCI device and connection manager initialized Nov 18 11:39:28 cafemusic kernel: Bluetooth: HCI socket layer initialized Nov 18 11:39:28 cafemusic kernel: Bluetooth: L2CAP socket layer initialized Nov 18 11:39:28 cafemusic kernel: Bluetooth: SCO socket layer initialized Nov 18 11:39:28 cafemusic kernel: Bluetooth: HCI UART driver ver 2.3 Nov 18 11:39:28 cafemusic kernel: Bluetooth: HCI UART protocol H4 registered Nov 18 11:39:28 cafemusic kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Nov 18 11:39:28 cafemusic kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Nov 18 11:39:28 cafemusic kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Nov 18 11:39:28 cafemusic kernel: Bluetooth: HCI UART protocol Broadcom registered Nov 18 11:39:28 cafemusic kernel: brcmfmac: F1 signature read @0x18000000=0x1541a9a6 Nov 18 11:39:28 cafemusic kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1 Nov 18 11:39:28 cafemusic kernel: brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43430-sdio.raspberrypi,model-zero-2-w.bin failed with error -2 Nov 18 11:39:28 cafemusic kernel: usbcore: registered new interface driver brcmfmac Nov 18 11:39:28 cafemusic kernel: uart-pl011 3f201000.serial: no DMA platform data Nov 18 11:39:28 cafemusic systemd[1]: Started File System Check Daemon to report status. Nov 18 11:39:28 cafemusic systemd-udevd[311]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 18 11:39:28 cafemusic systemd-udevd[316]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Nov 18 11:39:28 cafemusic systemd-fsck[366]: fsck.fat 4.1 (2017-01-24) Nov 18 11:39:28 cafemusic systemd-fsck[366]: 0x25: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Nov 18 11:39:28 cafemusic systemd-fsck[366]: Automatically removing dirty bit. Nov 18 11:39:28 cafemusic systemd-fsck[366]: Performing changes. Nov 18 11:39:28 cafemusic systemd-fsck[366]: /dev/mmcblk0p1: 409 files, 41773/46774 clusters Nov 18 11:39:28 cafemusic systemd[1]: Started File System Check on /dev/disk/by-uuid/DC0C-AF04. Nov 18 11:39:28 cafemusic kernel: Bluetooth: hci0: BCM: chip id 94 Nov 18 11:39:28 cafemusic kernel: Bluetooth: hci0: BCM: features 0x2e Nov 18 11:39:28 cafemusic kernel: Bluetooth: hci0: BCM43430A1 Nov 18 11:39:28 cafemusic kernel: Bluetooth: hci0: BCM43430A1 (001.002.009) build 0000 Nov 18 11:39:28 cafemusic kernel: Bluetooth: hci0: BCM43430A1 'brcm/BCM43430A1.hcd' Patch Nov 18 11:39:29 cafemusic kernel: usbcore: registered new interface driver snd-usb-audio Nov 18 11:39:29 cafemusic kernel: brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob available (err=-2) Nov 18 11:39:29 cafemusic kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Jul 19 2021 03:24:18 version 7.45.98 (TOB) (56df937 CY) FWID 01-8e14b897 Nov 18 11:39:29 cafemusic systemd-udevd[316]: Using default interface naming scheme 'v240'. Nov 18 11:39:29 cafemusic systemd-udevd[316]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 18 11:39:29 cafemusic kernel: Bluetooth: hci0: BCM: features 0x2e Nov 18 11:39:29 cafemusic kernel: Bluetooth: hci0: BCM43438A1 37.4MHz Raspberry Pi 3-0141 Nov 18 11:39:29 cafemusic kernel: Bluetooth: hci0: BCM43430A1 (001.002.009) build 0508 Nov 18 11:39:30 cafemusic systemd[1]: Created slice system-bthelper.slice. Nov 18 11:39:30 cafemusic systemd[1]: Condition check resulted in Huge Pages File System being skipped. Nov 18 11:39:30 cafemusic systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Nov 18 11:39:30 cafemusic systemd[1]: Starting Show Plymouth Boot Screen... Nov 18 11:39:30 cafemusic systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Nov 18 11:39:30 cafemusic systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Nov 18 11:39:30 cafemusic kernel: alsactl[405]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set Nov 18 11:39:30 cafemusic systemd-udevd[312]: Process '/bin/bash -c '/usr/local/bin/volumio usbattach'' failed with exit code 7. Nov 18 11:39:30 cafemusic systemd-udevd[313]: Process '/bin/bash -c '/usr/local/bin/volumio scanaudioinputs'' failed with exit code 7. Nov 18 11:39:30 cafemusic systemd[1]: Mounting /boot... Nov 18 11:39:30 cafemusic systemd[1]: plymouth-start.service: Succeeded. Nov 18 11:39:30 cafemusic systemd[1]: Started Show Plymouth Boot Screen. Nov 18 11:39:30 cafemusic systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Nov 18 11:39:30 cafemusic systemd[1]: Starting Load/Save RF Kill Switch Status... Nov 18 11:39:31 cafemusic systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Nov 18 11:39:31 cafemusic systemd[1]: Started Load/Save RF Kill Switch Status. Nov 18 11:39:31 cafemusic systemd[1]: Mounted /boot. Nov 18 11:39:31 cafemusic systemd[1]: Reached target Local File Systems. Nov 18 11:39:31 cafemusic systemd[1]: Starting Preprocess NFS configuration... Nov 18 11:39:31 cafemusic systemd[1]: Starting Create Volatile Files and Directories... Nov 18 11:39:31 cafemusic systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Nov 18 11:39:31 cafemusic systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Nov 18 11:39:31 cafemusic systemd[1]: Started ifup for wlan0. Nov 18 11:39:31 cafemusic systemd[1]: nfs-config.service: Succeeded. Nov 18 11:39:31 cafemusic systemd[1]: Started Preprocess NFS configuration. Nov 18 11:39:31 cafemusic systemd[1]: Received SIGRTMIN+20 from PID 161 (plymouthd). Nov 18 11:39:31 cafemusic systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Nov 18 11:39:31 cafemusic systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Nov 18 11:39:31 cafemusic systemd[1]: Reached target NFS client services. Nov 18 11:39:31 cafemusic systemd[1]: plymouth-read-write.service: Succeeded. Nov 18 11:39:31 cafemusic systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Nov 18 11:39:31 cafemusic systemd[1]: Started Create Volatile Files and Directories. Nov 18 11:39:31 cafemusic kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211 Nov 18 11:39:31 cafemusic systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Nov 18 11:39:31 cafemusic systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Nov 18 11:39:31 cafemusic systemd[1]: Starting Update UTMP about System Boot/Shutdown... Nov 18 11:39:31 cafemusic systemd[1]: Starting RPC bind portmap service... Nov 18 11:39:31 cafemusic systemd[1]: Started Update UTMP about System Boot/Shutdown. Nov 18 11:39:31 cafemusic systemd[1]: Reached target System Initialization. Nov 18 11:39:31 cafemusic systemd[1]: Started Daily Cleanup of Temporary Directories. Nov 18 11:39:31 cafemusic systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Nov 18 11:39:31 cafemusic systemd[1]: apt-daily.timer: Not using persistent file timestamp Fri 2025-12-19 06:00:23 UTC as it is in the future. Nov 18 11:39:31 cafemusic systemd[1]: Started Daily apt download activities. Nov 18 11:39:31 cafemusic systemd[1]: Listening on D-Bus System Message Bus Socket. Nov 18 11:39:31 cafemusic systemd[1]: Listening on triggerhappy.socket. Nov 18 11:39:31 cafemusic systemd[1]: Reached target Sockets. Nov 18 11:39:31 cafemusic systemd[1]: Reached target Basic System. Nov 18 11:39:31 cafemusic systemd[1]: Started Volumio Log Rotation Service. Nov 18 11:39:31 cafemusic systemd[1]: Started D-Bus System Message Bus. Nov 18 11:39:31 cafemusic systemd[1]: Starting WPA supplicant... Nov 18 11:39:31 cafemusic systemd[1]: Started UPnP Renderer front-end to MPD. Nov 18 11:39:31 cafemusic systemd[1]: Started Volumio Iptables Module. Nov 18 11:39:31 cafemusic kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 18 11:39:31 cafemusic systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Nov 18 11:39:31 cafemusic systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Nov 18 11:39:31 cafemusic systemd[1]: Started volumio-remote-updater.service. Nov 18 11:39:31 cafemusic systemd[1]: Starting Wireless Services... Nov 18 11:39:31 cafemusic systemd[1]: Starting triggerhappy global hotkey daemon... Nov 18 11:39:31 cafemusic systemd[1]: Started Manage Sound Card State (restore and store). Nov 18 11:39:31 cafemusic alsactl[462]: alsactl 1.1.8 daemon started Nov 18 11:39:31 cafemusic systemd[1]: Starting Save/Restore Sound Card State... Nov 18 11:39:31 cafemusic systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Nov 18 11:39:31 cafemusic systemd[1]: Starting dhcpcd on all interfaces... Nov 18 11:39:31 cafemusic systemd[1]: Starting Configure Bluetooth Modems connected by UART... Nov 18 11:39:31 cafemusic systemd[1]: Starting Login Service... Nov 18 11:39:31 cafemusic systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Nov 18 11:39:31 cafemusic systemd[1]: Starting Volumio Time Update Utility... Nov 18 11:39:31 cafemusic systemd[1]: apt-daily-upgrade.timer: Not using persistent file timestamp Fri 2025-12-19 06:00:23 UTC as it is in the future. Nov 18 11:39:31 cafemusic systemd[1]: Started Daily apt upgrade and clean activities. Nov 18 11:39:31 cafemusic systemd[1]: Reached target Timers. Nov 18 11:39:31 cafemusic systemd[1]: Started RPC bind portmap service. Nov 18 11:39:31 cafemusic systemd[1]: Started Helper to synchronize boot up for ifupdown. Nov 18 11:39:31 cafemusic systemd[1]: Starting Raise network interfaces... Nov 18 11:39:31 cafemusic systemd[1]: Reached target Remote File Systems (Pre). Nov 18 11:39:31 cafemusic systemd[1]: Reached target Remote File Systems. Nov 18 11:39:31 cafemusic systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Nov 18 11:39:31 cafemusic systemd[1]: Reached target RPC Port Mapper. Nov 18 11:39:31 cafemusic volumio-time-update[467]: volumio-time-update-util: Fetching time from Volumio... Nov 18 11:39:31 cafemusic thd[461]: Unable to parse trigger line: Nov 18 11:39:31 cafemusic thd[461]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Nov 18 11:39:31 cafemusic thd[461]: Unable to parse trigger line: Nov 18 11:39:31 cafemusic thd[461]: Found socket passed from systemd Nov 18 11:39:31 cafemusic systemd-logind[466]: New seat seat0. Nov 18 11:39:31 cafemusic dhcpcd[464]: dev: loaded udev Nov 18 11:39:31 cafemusic avahi-daemon[456]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Nov 18 11:39:31 cafemusic avahi-daemon[456]: Successfully dropped root privileges. Nov 18 11:39:31 cafemusic avahi-daemon[456]: avahi-daemon 0.7 starting up. Nov 18 11:39:32 cafemusic kernel: 8021q: 802.1Q VLAN Support v1.8 Nov 18 11:39:32 cafemusic dhcpcd[464]: forked to background, child pid 561 Nov 18 11:39:32 cafemusic volumio-remote-updater[459]: Error: No active session Nov 18 11:39:32 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:32] [info] asio async_connect error: system:111 (Connection refused) Nov 18 11:39:32 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:32] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 18 11:39:32 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:32] [error] handle_connect error: Underlying Transport Error Nov 18 11:39:32 cafemusic volumio-time-update[467]: volumio-time-update-util: Date not found in response Nov 18 11:39:32 cafemusic volumio-time-update[467]: volumio-time-update-util: Retrying in 5 seconds... Nov 18 11:39:32 cafemusic volumio[454]: Could not open config: /tmp/upmpdcli.conf Nov 18 11:39:32 cafemusic dbus-daemon[451]: [system] Successfully activated service 'org.freedesktop.systemd1' Nov 18 11:39:32 cafemusic systemd[1]: Started Login Service. Nov 18 11:39:32 cafemusic systemd[1]: Started triggerhappy global hotkey daemon. Nov 18 11:39:32 cafemusic systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Nov 18 11:39:32 cafemusic systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Nov 18 11:39:32 cafemusic systemd[1]: Started Save/Restore Sound Card State. Nov 18 11:39:32 cafemusic systemd[1]: Started dhcpcd on all interfaces. Nov 18 11:39:32 cafemusic systemd[1]: hciuart.service: Succeeded. Nov 18 11:39:32 cafemusic systemd[1]: Started Configure Bluetooth Modems connected by UART. Nov 18 11:39:32 cafemusic avahi-daemon[456]: Successfully called chroot(). Nov 18 11:39:32 cafemusic avahi-daemon[456]: Successfully dropped remaining capabilities. Nov 18 11:39:32 cafemusic wpa_supplicant[452]: Successfully initialized wpa_supplicant Nov 18 11:39:32 cafemusic dhcpcd-run-hooks[572]: wlan0: starting wpa_supplicant Nov 18 11:39:32 cafemusic avahi-daemon[456]: Loading service file /services/volumio.service. Nov 18 11:39:32 cafemusic avahi-daemon[456]: Network interface enumeration completed. Nov 18 11:39:32 cafemusic avahi-daemon[456]: Server startup complete. Host name is cafemusic.local. Local service cookie is 3761745818. Nov 18 11:39:32 cafemusic avahi-daemon[456]: Service "CafeMusic" (/services/volumio.service) successfully established. Nov 18 11:39:32 cafemusic systemd[1]: Started Avahi mDNS/DNS-SD Stack. Nov 18 11:39:32 cafemusic ifup[469]: ifup: waiting for lock on /run/network/ifstate.wlan0 Nov 18 11:39:32 cafemusic systemd[1]: Started WPA supplicant. Nov 18 11:39:32 cafemusic sh[428]: wlan0=wlan0 Nov 18 11:39:32 cafemusic systemd[1]: Starting Raspberry Pi bluetooth helper... Nov 18 11:39:32 cafemusic systemd[1]: Reached target Sound Card. Nov 18 11:39:32 cafemusic systemd[1]: Started Raise network interfaces. Nov 18 11:39:32 cafemusic systemd[1]: Reached target Network. Nov 18 11:39:32 cafemusic systemd[1]: Starting Network Time Service... Nov 18 11:39:32 cafemusic bthelper[581]: Raspberry Pi BDADDR already set Nov 18 11:39:32 cafemusic systemd[1]: Starting Permit User Sessions... Nov 18 11:39:32 cafemusic dhcpcd[561]: wlan0: connected to Access Point `' Nov 18 11:39:32 cafemusic systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Nov 18 11:39:32 cafemusic systemd[1]: Starting OpenBSD Secure Shell server... Nov 18 11:39:32 cafemusic systemd[1]: Reached target Network is Online. Nov 18 11:39:32 cafemusic systemd[1]: Starting /etc/rc.local Compatibility... Nov 18 11:39:32 cafemusic systemd[1]: Starting LSB: Brings up/down network automatically... Nov 18 11:39:32 cafemusic systemd[1]: Starting Samba NMB Daemon... Nov 18 11:39:32 cafemusic systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 18 11:39:32 cafemusic systemd[1]: Started Raspberry Pi bluetooth helper. Nov 18 11:39:33 cafemusic systemd[1]: Started Permit User Sessions. Nov 18 11:39:33 cafemusic systemd[1]: Started /etc/rc.local Compatibility. Nov 18 11:39:33 cafemusic systemd[1]: iptables.service: Succeeded. Nov 18 11:39:33 cafemusic systemd[1]: Starting Terminate Plymouth Boot Screen... Nov 18 11:39:33 cafemusic systemd[1]: Starting Hold until boot process finishes up... Nov 18 11:39:33 cafemusic haveged[441]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Nov 18 11:39:33 cafemusic haveged[441]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Nov 18 11:39:33 cafemusic haveged[441]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00234 Nov 18 11:39:33 cafemusic haveged[441]: haveged: fills: 0, generated: 0 Nov 18 11:39:33 cafemusic systemd[1]: Starting Bluetooth service... Nov 18 11:39:33 cafemusic systemd[1]: Received SIGRTMIN+21 from PID 161 (plymouthd). Nov 18 11:39:33 cafemusic systemd[1]: Received SIGRTMIN+21 from PID 161 (plymouthd). Nov 18 11:39:33 cafemusic systemd[1]: plymouth-quit.service: Succeeded. Nov 18 11:39:33 cafemusic systemd[1]: Started Terminate Plymouth Boot Screen. Nov 18 11:39:33 cafemusic systemd[1]: plymouth-quit-wait.service: Succeeded. Nov 18 11:39:33 cafemusic systemd[1]: Started Hold until boot process finishes up. Nov 18 11:39:33 cafemusic loadcpufreq[470]: Loading cpufreq kernel modules...done (none). Nov 18 11:39:33 cafemusic systemd[1]: Started Getty on tty1. Nov 18 11:39:33 cafemusic systemd[1]: Reached target Login Prompts. Nov 18 11:39:33 cafemusic systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Nov 18 11:39:33 cafemusic systemd[1]: Starting LSB: set CPUFreq kernel parameters... Nov 18 11:39:33 cafemusic ifplugd[646]: Network Interface Plugging Daemon...skip eth0...done. Nov 18 11:39:33 cafemusic systemd[1]: Started LSB: Brings up/down network automatically. Nov 18 11:39:33 cafemusic dhcpcd[561]: wlan0: waiting for carrier Nov 18 11:39:33 cafemusic ntpd[619]: ntpd 4.2.8p12@1.3728-o (1): Starting Nov 18 11:39:33 cafemusic cpufrequtils[670]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Nov 18 11:39:33 cafemusic systemd[1]: Started Network Time Service. Nov 18 11:39:33 cafemusic ntpd[619]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Nov 18 11:39:33 cafemusic systemd[1]: Started LSB: set CPUFreq kernel parameters. Nov 18 11:39:33 cafemusic ntpd[692]: proto: precision = 0.833 usec (-20) Nov 18 11:39:33 cafemusic ntpd[692]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Nov 18 11:39:33 cafemusic ntpd[692]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Nov 18 11:39:33 cafemusic ntpd[692]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 326 days ago Nov 18 11:39:33 cafemusic ntpd[692]: Listen and drop on 0 v6wildcard [::]:123 Nov 18 11:39:33 cafemusic ntpd[692]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Nov 18 11:39:33 cafemusic ntpd[692]: Listen normally on 2 lo 127.0.0.1:123 Nov 18 11:39:33 cafemusic ntpd[692]: Listening on routing socket on fd #19 for interface updates Nov 18 11:39:33 cafemusic ntpd[692]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 18 11:39:33 cafemusic ntpd[692]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 18 11:39:33 cafemusic bluetoothd[665]: Bluetooth daemon 5.83 Nov 18 11:39:33 cafemusic sshd[691]: Server listening on 0.0.0.0 port 22. Nov 18 11:39:33 cafemusic sshd[691]: Server listening on :: port 22. Nov 18 11:39:33 cafemusic systemd[1]: Started OpenBSD Secure Shell server. Nov 18 11:39:33 cafemusic bluetoothd[665]: src/main.c:check_options() Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Nov 18 11:39:33 cafemusic systemd[1]: Started Bluetooth service. Nov 18 11:39:33 cafemusic systemd[1]: Reached target Bluetooth. Nov 18 11:39:33 cafemusic bluetoothd[665]: Starting SDP server Nov 18 11:39:33 cafemusic bluetoothd[665]: Excluding (cli) hostname Nov 18 11:39:33 cafemusic bluetoothd[665]: Excluding (cli) scanparam Nov 18 11:39:33 cafemusic bluetoothd[665]: Excluding (cli) battery Nov 18 11:39:33 cafemusic bluetoothd[665]: Bluetooth management interface 1.22 initialized Nov 18 11:39:33 cafemusic bluetoothd[665]: Battery Provider Manager created Nov 18 11:39:33 cafemusic kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Nov 18 11:39:33 cafemusic kernel: Bluetooth: BNEP filters: protocol multicast Nov 18 11:39:33 cafemusic kernel: Bluetooth: BNEP socket layer initialized Nov 18 11:39:33 cafemusic kernel: Bluetooth: MGMT ver 1.22 Nov 18 11:39:33 cafemusic kernel: NET: Registered PF_ALG protocol family Nov 18 11:39:33 cafemusic kernel: cryptd: max_cpu_qlen set to 1000 Nov 18 11:39:34 cafemusic bluetoothd[665]: Failed to set privacy: Rejected (0x0b) Nov 18 11:39:34 cafemusic ntpd[692]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Nov 18 11:39:34 cafemusic nmbd[662]: [2025/11/18 11:39:34.541233, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Nov 18 11:39:34 cafemusic nmbd[662]: started asyncdns process 715 Nov 18 11:39:34 cafemusic nmbd[662]: [2025/11/18 11:39:34.543999, 0] ../lib/util/become_daemon.c:149(daemon_status) Nov 18 11:39:34 cafemusic nmbd[662]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Nov 18 11:39:34 cafemusic nmbd[662]: [2025/11/18 11:39:34.544335, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Nov 18 11:39:34 cafemusic nmbd[662]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Nov 18 11:39:34 cafemusic wireless.js[460]: Cleaning previous... Nov 18 11:39:35 cafemusic sudo[723]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Nov 18 11:39:35 cafemusic sudo[723]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:35 cafemusic sudo[723]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:35 cafemusic sudo[725]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Nov 18 11:39:35 cafemusic sudo[725]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:35 cafemusic ntpd[692]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Nov 18 11:39:35 cafemusic sudo[725]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:35 cafemusic wireless.js[460]: Stopped aP Nov 18 11:39:35 cafemusic sudo[732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 18 11:39:35 cafemusic sudo[732]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:35 cafemusic kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 18 11:39:35 cafemusic sudo[732]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:35 cafemusic sudo[734]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Nov 18 11:39:35 cafemusic sudo[734]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:36 cafemusic sudo[734]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:36 cafemusic sudo[741]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 18 11:39:36 cafemusic sudo[741]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:36 cafemusic sudo[741]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:36 cafemusic systemd[1]: systemd-rfkill.service: Succeeded. Nov 18 11:39:36 cafemusic sudo[743]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Nov 18 11:39:36 cafemusic sudo[743]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:36 cafemusic ntpd[692]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Nov 18 11:39:36 cafemusic sudo[743]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:36 cafemusic wireless.js[460]: Start wireless flow Nov 18 11:39:36 cafemusic wireless.js[460]: Stopped hotspot (if there).. Nov 18 11:39:36 cafemusic sudo[748]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Nov 18 11:39:36 cafemusic sudo[748]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:36 cafemusic sudo[748]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:36 cafemusic sudo[750]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Nov 18 11:39:36 cafemusic sudo[750]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:37 cafemusic volumio-time-update[467]: volumio-time-update-util: Fetching time from Volumio... Nov 18 11:39:37 cafemusic volumio-time-update[467]: volumio-time-update-util: Date not found in response Nov 18 11:39:37 cafemusic volumio-time-update[467]: volumio-time-update-util: Retrying in 5 seconds... Nov 18 11:39:37 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:37] [info] asio async_connect error: system:111 (Connection refused) Nov 18 11:39:37 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:37] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 18 11:39:37 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:37] [error] handle_connect error: Underlying Transport Error Nov 18 11:39:37 cafemusic sudo[750]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:37 cafemusic wireless.js[460]: DHCP IP Nov 18 11:39:37 cafemusic wireless.js[460]: Start ap Nov 18 11:39:37 cafemusic wpa_supplicant[757]: Successfully initialized wpa_supplicant Nov 18 11:39:37 cafemusic sudo[758]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Nov 18 11:39:37 cafemusic sudo[758]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:37 cafemusic dhcpcd[759]: sending commands to master dhcpcd process Nov 18 11:39:37 cafemusic dhcpcd[561]: control command: /sbin/dhcpcd Nov 18 11:39:37 cafemusic kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 18 11:39:37 cafemusic sudo[758]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:37 cafemusic dhcpcd[561]: lo: carrier acquired Nov 18 11:39:37 cafemusic dhcpcd[561]: DUID 00:01:00:01:2a:5e:ec:30:b8:27:eb:d7:44:11 Nov 18 11:39:37 cafemusic dhcpcd[561]: lo: IAID 6c:6f:00:00 Nov 18 11:39:37 cafemusic dhcpcd[561]: lo: ipv6_start: Operation not supported Nov 18 11:39:37 cafemusic dhcpcd[561]: lo: using static address 127.0.0.1/8 Nov 18 11:39:37 cafemusic dhcpcd[561]: lo: adding route to 127.0.0.0/8 Nov 18 11:39:37 cafemusic dhcpcd[561]: arp_announce: Invalid argument Nov 18 11:39:37 cafemusic ntpd[692]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Nov 18 11:39:37 cafemusic bluetoothd[665]: src/adv_monitor.c:btd_adv_monitor_power_down() Unexpected NULL btd_adv_monitor_manager object upon power down Nov 18 11:39:37 cafemusic bthelper[581]: [NEW] Media /org/bluez/hci0 Nov 18 11:39:37 cafemusic bthelper[581]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Nov 18 11:39:37 cafemusic bthelper[581]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Nov 18 11:39:37 cafemusic bthelper[581]: hci0 class of device changed: 0x000000 Nov 18 11:39:37 cafemusic bthelper[581]: hci0 new_settings: ssp br/edr le secure-conn Nov 18 11:39:37 cafemusic bthelper[581]: [CHG] Controller E4:5F:01:F4:3F:7F PowerState: on-disabling Nov 18 11:39:37 cafemusic bthelper[581]: Changing power off succeeded Nov 18 11:39:37 cafemusic bthelper[581]: [CHG] Controller E4:5F:01:F4:3F:7F PowerState: off Nov 18 11:39:37 cafemusic bthelper[581]: [CHG] Controller E4:5F:01:F4:3F:7F Powered: no Nov 18 11:39:37 cafemusic bthelper[581]: [CHG] Controller E4:5F:01:F4:3F:7F Discovering: no Nov 18 11:39:37 cafemusic bthelper[581]: [CHG] Controller E4:5F:01:F4:3F:7F Class: 0x00000000 (0) Nov 18 11:39:37 cafemusic bthelper[581]: [NEW] Media /org/bluez/hci0 Nov 18 11:39:37 cafemusic bthelper[581]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Nov 18 11:39:37 cafemusic bthelper[581]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Nov 18 11:39:37 cafemusic bthelper[581]: [CHG] Controller E4:5F:01:F4:3F:7F PowerState: off-enabling Nov 18 11:39:38 cafemusic bthelper[581]: hci0 class of device changed: 0x00041c Nov 18 11:39:38 cafemusic bthelper[581]: [CHG] Controller E4:5F:01:F4:3F:7F Class: 0x0000041c (1052) Nov 18 11:39:38 cafemusic bthelper[581]: hci0 new_settings: powered ssp br/edr le secure-conn Nov 18 11:39:38 cafemusic bthelper[581]: Changing power on succeeded Nov 18 11:39:38 cafemusic wireless.js[460]: trying... Nov 18 11:39:38 cafemusic sudo[788]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:38 cafemusic sudo[788]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:38 cafemusic sudo[788]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:39 cafemusic wireless.js[460]: trying... Nov 18 11:39:39 cafemusic sudo[791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:39 cafemusic sudo[791]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:39 cafemusic sudo[791]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:40 cafemusic wireless.js[460]: trying... Nov 18 11:39:40 cafemusic sudo[794]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:40 cafemusic sudo[794]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:40 cafemusic sudo[794]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:41 cafemusic wireless.js[460]: trying... Nov 18 11:39:41 cafemusic sudo[797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:41 cafemusic sudo[797]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:41 cafemusic sudo[797]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:42 cafemusic volumio-time-update[467]: volumio-time-update-util: Fetching time from Volumio... Nov 18 11:39:42 cafemusic wireless.js[460]: trying... Nov 18 11:39:42 cafemusic volumio-time-update[467]: volumio-time-update-util: Date not found in response Nov 18 11:39:42 cafemusic volumio-time-update[467]: volumio-time-update-util: Retrying in 5 seconds... Nov 18 11:39:42 cafemusic sudo[805]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:42 cafemusic sudo[805]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:42 cafemusic sudo[805]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:43 cafemusic wireless.js[460]: trying... Nov 18 11:39:43 cafemusic sudo[808]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:43 cafemusic sudo[808]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:43 cafemusic sudo[808]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:44 cafemusic wireless.js[460]: trying... Nov 18 11:39:44 cafemusic sudo[811]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:44 cafemusic sudo[811]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:44 cafemusic sudo[811]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:44 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:44] [info] asio async_connect error: system:111 (Connection refused) Nov 18 11:39:44 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:44] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 18 11:39:44 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:44] [error] handle_connect error: Underlying Transport Error Nov 18 11:39:45 cafemusic wireless.js[460]: trying... Nov 18 11:39:45 cafemusic sudo[814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:45 cafemusic sudo[814]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:45 cafemusic sudo[814]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:46 cafemusic wireless.js[460]: trying... Nov 18 11:39:46 cafemusic sudo[817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:46 cafemusic sudo[817]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:46 cafemusic sudo[817]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:47 cafemusic wireless.js[460]: trying... Nov 18 11:39:47 cafemusic volumio-time-update[467]: volumio-time-update-util: Fetching time from Volumio... Nov 18 11:39:47 cafemusic sudo[824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:47 cafemusic sudo[824]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:47 cafemusic volumio-time-update[467]: volumio-time-update-util: Date not found in response Nov 18 11:39:47 cafemusic volumio-time-update[467]: volumio-time-update-util: Retrying in 5 seconds... Nov 18 11:39:47 cafemusic sudo[824]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:48 cafemusic wireless.js[460]: trying... Nov 18 11:39:48 cafemusic sudo[828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:48 cafemusic sudo[828]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:48 cafemusic sudo[828]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:49 cafemusic wpa_supplicant[764]: wlan0: Failed to initiate sched scan Nov 18 11:39:49 cafemusic wireless.js[460]: trying... Nov 18 11:39:49 cafemusic sudo[831]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:49 cafemusic sudo[831]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:49 cafemusic sudo[831]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:50 cafemusic wireless.js[460]: trying... Nov 18 11:39:50 cafemusic sudo[834]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:50 cafemusic sudo[834]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:50 cafemusic sudo[834]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:51 cafemusic wireless.js[460]: trying... Nov 18 11:39:51 cafemusic sudo[837]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:51 cafemusic sudo[837]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:51 cafemusic sudo[837]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:52 cafemusic wireless.js[460]: trying... Nov 18 11:39:52 cafemusic sudo[840]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:52 cafemusic sudo[840]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:52 cafemusic volumio-time-update[467]: volumio-time-update-util: Fetching time from Volumio... Nov 18 11:39:52 cafemusic sudo[840]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:52 cafemusic volumio-time-update[467]: volumio-time-update-util: Date not found in response Nov 18 11:39:52 cafemusic volumio-time-update[467]: volumio-time-update-util: Retrying in 5 seconds... Nov 18 11:39:53 cafemusic wireless.js[460]: trying... Nov 18 11:39:53 cafemusic sudo[848]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:53 cafemusic sudo[848]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:53 cafemusic sudo[848]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:54 cafemusic wireless.js[460]: trying... Nov 18 11:39:54 cafemusic sudo[851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:54 cafemusic sudo[851]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:54 cafemusic sudo[851]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:54 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:54] [info] asio async_connect error: system:111 (Connection refused) Nov 18 11:39:54 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:54] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 18 11:39:54 cafemusic volumio-remote-updater[459]: [2025-11-18 11:39:54] [error] handle_connect error: Underlying Transport Error Nov 18 11:39:54 cafemusic wpa_supplicant[764]: wlan0: Trying to associate with SSID 'Solid Ground Staff 2.4G' Nov 18 11:39:55 cafemusic wireless.js[460]: trying... Nov 18 11:39:55 cafemusic sudo[854]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:55 cafemusic sudo[854]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:55 cafemusic sudo[854]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:56 cafemusic wireless.js[460]: trying... Nov 18 11:39:56 cafemusic sudo[857]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:56 cafemusic sudo[857]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:56 cafemusic sudo[857]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:57 cafemusic wireless.js[460]: trying... Nov 18 11:39:57 cafemusic sudo[860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Nov 18 11:39:57 cafemusic sudo[860]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:39:57 cafemusic sudo[860]: pam_unix(sudo:session): session closed for user root Nov 18 11:39:57 cafemusic volumio-time-update[467]: volumio-time-update-util: Fetching time from Volumio... Nov 18 11:39:57 cafemusic volumio-time-update[467]: volumio-time-update-util: Date not found in response Nov 18 11:39:57 cafemusic volumio-time-update[467]: volumio-time-update-util: Retrying in 5 seconds... Nov 18 11:39:58 cafemusic wireless.js[460]: Overtime, starting plan B Nov 18 11:39:58 cafemusic systemd[1]: Started Wireless Services. Nov 18 11:39:58 cafemusic kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 18 11:39:58 cafemusic systemd[1]: Started Volumio Backend Module. Nov 18 11:39:58 cafemusic systemd[1]: Started Volumio Cpu Tweaker. Nov 18 11:39:58 cafemusic volumio-cpu-tweak[871]: Setting RT Priority for mpd Nov 18 11:39:58 cafemusic volumio-cpu-tweak[871]: pid 35's current scheduling policy: SCHED_OTHER Nov 18 11:39:58 cafemusic volumio-cpu-tweak[871]: pid 35's current scheduling priority: 0 Nov 18 11:39:58 cafemusic volumio-cpu-tweak[871]: Setting MPD Affinity Nov 18 11:39:58 cafemusic volumio-cpu-tweak[871]: pid 3's current affinity mask: f Nov 18 11:39:58 cafemusic volumio-cpu-tweak[871]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Nov 18 11:39:58 cafemusic volumio-cpu-tweak[871]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Nov 18 11:39:58 cafemusic systemd[1]: volumio_cpu_tweak.service: Succeeded. Nov 18 11:39:58 cafemusic systemd[1]: systemd-fsckd.service: Succeeded. Nov 18 11:40:01 cafemusic volumio[870]: info: ------------------------------------------- Nov 18 11:40:01 cafemusic volumio[870]: info: ----- Volumio3 ---- Nov 18 11:40:01 cafemusic volumio[870]: info: ------------------------------------------- Nov 18 11:40:01 cafemusic volumio[870]: info: ----- System startup ---- Nov 18 11:40:01 cafemusic volumio[870]: info: ------------------------------------------- Nov 18 11:40:02 cafemusic volumio-time-update[467]: volumio-time-update-util: Fetching time from Volumio... Nov 18 11:40:02 cafemusic volumio-time-update[467]: volumio-time-update-util: Date not found in response Nov 18 11:40:02 cafemusic volumio-time-update[467]: volumio-time-update-util: Retrying in 5 seconds... Nov 18 11:40:02 cafemusic volumio[870]: info: MYVOLUMIO Environment detected Nov 18 11:40:03 cafemusic volumio[870]: info: Plugin folders cleanup Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning into folder /volumio/app/plugins/ Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning category audio_interface Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning category miscellanea Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning category music_service Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning category plugins.json Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning category system_controller Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning category user_interface Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning into folder /data/plugins/ Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning category audio_interface Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning category music_service Nov 18 11:40:03 cafemusic volumio[870]: info: Scanning category system_controller Nov 18 11:40:03 cafemusic volumio[870]: info: Plugin folders cleanup completed Nov 18 11:40:03 cafemusic volumio[870]: info: ------------------------------------------- Nov 18 11:40:03 cafemusic volumio[870]: info: ----- Core plugins startup ---- Nov 18 11:40:03 cafemusic volumio[870]: info: ------------------------------------------- Nov 18 11:40:03 cafemusic volumio[870]: info: Loading plugins from folder /volumio/app/plugins/ Nov 18 11:40:03 cafemusic volumio[870]: info: Adding plugin upnp to MyMusic Plugins Nov 18 11:40:03 cafemusic volumio[870]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 18 11:40:03 cafemusic volumio[870]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 18 11:40:03 cafemusic volumio[870]: info: Loading plugins from folder /data/plugins/ Nov 18 11:40:03 cafemusic volumio[870]: info: Loading plugin "system"... Nov 18 11:40:03 cafemusic volumio[870]: info: Loading plugin "appearance"... Nov 18 11:40:04 cafemusic volumio-remote-updater[459]: [2025-11-18 11:40:04] [connect] Successful connection Nov 18 11:40:04 cafemusic wpa_supplicant[764]: wlan0: Authentication with 0c:ea:14:8b:ac:2e timed out. Nov 18 11:40:04 cafemusic wpa_supplicant[764]: wlan0: CTRL-EVENT-DISCONNECTED bssid=0c:ea:14:8b:ac:2e reason=3 locally_generated=1 Nov 18 11:40:04 cafemusic wpa_supplicant[764]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Nov 18 11:40:04 cafemusic wpa_supplicant[764]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=ZA Nov 18 11:40:05 cafemusic volumio[870]: info: Loading plugin "network"... Nov 18 11:40:05 cafemusic volumio[870]: info: Refreshing Cached IP Addresses Nov 18 11:40:05 cafemusic sudo[908]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 18 11:40:05 cafemusic sudo[908]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:05 cafemusic sudo[910]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 18 11:40:05 cafemusic sudo[910]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:05 cafemusic sudo[910]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:05 cafemusic volumio[870]: info: Loading plugin "services"... Nov 18 11:40:05 cafemusic volumio[870]: info: Loading plugin "alsa_controller"... Nov 18 11:40:05 cafemusic sudo[908]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:05 cafemusic sudo[920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 18 11:40:05 cafemusic sudo[920]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:05 cafemusic sudo[920]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:05 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 18 11:40:05 cafemusic volumio[870]: info: Loading plugin "wizard"... Nov 18 11:40:05 cafemusic volumio[870]: info: Loading plugin "networkfs"... Nov 18 11:40:05 cafemusic volumio[870]: info: Starting Udev Watcher for removable devices Nov 18 11:40:05 cafemusic sudo[938]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.4/Music(Backup) /mnt/NAS/Music(Backup) Nov 18 11:40:05 cafemusic sudo[938]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:05 cafemusic sudo[940]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Stephan,password=SG$erv3r,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.3/Storage/Volumio_Music_Files/CafeMusic /mnt/NAS/ServerMusic Nov 18 11:40:05 cafemusic sudo[940]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:05 cafemusic volumio[870]: info: Ignoring mount for partition: boot Nov 18 11:40:05 cafemusic volumio[870]: info: Ignoring mount for partition: volumio Nov 18 11:40:05 cafemusic volumio[870]: info: Ignoring mount for partition: volumio_data Nov 18 11:40:05 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 18 11:40:05 cafemusic volumio[870]: info: Loading plugin "volumio_command_line_client"... Nov 18 11:40:05 cafemusic volumio[870]: info: Loading plugin "upnp"... Nov 18 11:40:05 cafemusic volumio[870]: info: [1763466005481] Starting Upmpd Daemon Nov 18 11:40:05 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 18 11:40:05 cafemusic volumio[870]: info: Loading plugin "my_music"... Nov 18 11:40:05 cafemusic volumio[870]: info: Loading plugin "mpd"... Nov 18 11:40:05 cafemusic wpa_supplicant[764]: wlan0: Trying to associate with SSID 'SGIOT' Nov 18 11:40:05 cafemusic kernel: Key type cifs.spnego registered Nov 18 11:40:05 cafemusic kernel: Key type cifs.idmap registered Nov 18 11:40:05 cafemusic 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. Nov 18 11:40:05 cafemusic kernel: CIFS: Attempting to mount //192.168.0.3/Storage/Volumio_Music_Files/CafeMusic Nov 18 11:40:05 cafemusic kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Nov 18 11:40:05 cafemusic kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Nov 18 11:40:05 cafemusic kernel: CIFS: Attempting to mount //192.168.0.4/Music(Backup) Nov 18 11:40:05 cafemusic kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Nov 18 11:40:05 cafemusic kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Nov 18 11:40:05 cafemusic sudo[940]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:05 cafemusic sudo[938]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:05 cafemusic wpa_supplicant[764]: wlan0: Associated with 1e:ec:da:69:e6:4a Nov 18 11:40:05 cafemusic wpa_supplicant[764]: wlan0: CTRL-EVENT-CONNECTED - Connection to 1e:ec:da:69:e6:4a completed [id=0 id_str=] Nov 18 11:40:05 cafemusic dhcpcd[561]: wlan0: carrier acquired Nov 18 11:40:05 cafemusic wpa_supplicant[764]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Nov 18 11:40:05 cafemusic dhcpcd[561]: wlan0: connected to Access Point `SGIOT' Nov 18 11:40:05 cafemusic dhcpcd[561]: wlan0: IAID 01:f4:3f:7e Nov 18 11:40:05 cafemusic dhcpcd[561]: wlan0: adding address fe80::e65f:1ff:fef4:3f7e Nov 18 11:40:05 cafemusic dhcpcd[561]: ipv6_addaddr1: Permission denied Nov 18 11:40:05 cafemusic dhcpcd[561]: wlan0: probing address 192.168.0.84/24 Nov 18 11:40:05 cafemusic dhcpcd[561]: wlan0: soliciting an IPv6 router Nov 18 11:40:06 cafemusic volumio[870]: info: Loading plugin "upnp_browser"... Nov 18 11:40:06 cafemusic volumio[870]: info: Loading plugin "alarm-clock"... Nov 18 11:40:06 cafemusic volumio[870]: info: Loading plugin "airplay_emulation"... Nov 18 11:40:06 cafemusic volumio[870]: info: Starting Shairport Sync Nov 18 11:40:06 cafemusic volumio[870]: info: Loading plugin "last_100"... Nov 18 11:40:07 cafemusic volumio[870]: info: Loading plugin "webradio"... Nov 18 11:40:07 cafemusic volumio[870]: info: Loading plugin "i2s_dacs"... Nov 18 11:40:07 cafemusic volumio[870]: info: I2S DAC not set, start Auto-detection Nov 18 11:40:07 cafemusic volumio[870]: info: Loading plugin "volumiodiscovery"... Nov 18 11:40:07 cafemusic volumio[870]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 18 11:40:07 cafemusic volumio[870]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 18 11:40:07 cafemusic volumio[870]: *** WARNING *** For more information see Nov 18 11:40:07 cafemusic node[870]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 18 11:40:07 cafemusic volumio[870]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 18 11:40:07 cafemusic volumio[870]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 18 11:40:07 cafemusic volumio[870]: *** WARNING *** For more information see Nov 18 11:40:07 cafemusic node[870]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 18 11:40:07 cafemusic node[870]: *** WARNING *** For more information see Nov 18 11:40:07 cafemusic node[870]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 18 11:40:07 cafemusic node[870]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 18 11:40:07 cafemusic node[870]: *** WARNING *** For more information see Nov 18 11:40:07 cafemusic volumio[870]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 18 11:40:07 cafemusic volumio[870]: info: Discovery: Started advertising with name: CafeMusic Nov 18 11:40:07 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 18 11:40:07 cafemusic volumio[870]: info: Plugin youtube2 is not enabled Nov 18 11:40:07 cafemusic volumio[870]: info: Loading plugin "ytcr"... Nov 18 11:40:07 cafemusic volumio-time-update[467]: volumio-time-update-util: Fetching time from Volumio... Nov 18 11:40:07 cafemusic volumio-time-update[467]: volumio-time-update-util: Date not found in response Nov 18 11:40:07 cafemusic volumio-time-update[467]: volumio-time-update-util: Retrying in 5 seconds... Nov 18 11:40:09 cafemusic volumio[870]: info: Plugin ytmusic is not enabled Nov 18 11:40:09 cafemusic volumio[870]: info: Loading plugin "autostart"... Nov 18 11:40:10 cafemusic volumio[870]: info: Applying required configuration parameters for plugin autostart Nov 18 11:40:10 cafemusic volumio[870]: info: AutoStart - onVolumioStart - read config.json Nov 18 11:40:10 cafemusic volumio[870]: info: Loading plugin "outputs"... Nov 18 11:40:10 cafemusic volumio[870]: info: Loading plugin "albumart"... Nov 18 11:40:10 cafemusic volumio[870]: info: Plugin example_plugin is not enabled Nov 18 11:40:10 cafemusic volumio[870]: info: Loading plugin "inputs"... Nov 18 11:40:10 cafemusic volumio[870]: info: Loading plugin "updater_comm"... Nov 18 11:40:10 cafemusic volumio[870]: info: Plugin mpdemulation is not enabled Nov 18 11:40:10 cafemusic volumio[870]: info: Loading plugin "rest_api"... Nov 18 11:40:10 cafemusic volumio[870]: info: Loading plugin "websocket"... Nov 18 11:40:10 cafemusic volumio[870]: info: Starting Socket.io Server version 2.3.0 Nov 18 11:40:10 cafemusic volumio[870]: info: Loading plugin "fusiondsp"... Nov 18 11:40:10 cafemusic volumio[870]: Forking 3 albumart workers Nov 18 11:40:11 cafemusic dhcpcd[561]: wlan0: using static address 192.168.0.84/24 Nov 18 11:40:11 cafemusic avahi-daemon[456]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.84. Nov 18 11:40:11 cafemusic dhcpcd[561]: wlan0: adding route to 192.168.0.0/24 Nov 18 11:40:11 cafemusic dhcpcd[561]: wlan0: adding default route via 192.168.0.1 Nov 18 11:40:11 cafemusic avahi-daemon[456]: New relevant interface wlan0.IPv4 for mDNS. Nov 18 11:40:11 cafemusic avahi-daemon[456]: Registering new address record for 192.168.0.84 on wlan0.IPv4. Nov 18 11:40:11 cafemusic volumio[870]: info: Applying required configuration parameters for plugin fusiondsp Nov 18 11:40:11 cafemusic volumio[870]: info: Loading i18n strings for locale en Nov 18 11:40:11 cafemusic volumio[870]: Updating browse sources language Nov 18 11:40:11 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 18 11:40:12 cafemusic volumio[870]: Starting albumart workers Nov 18 11:40:12 cafemusic volumio[870]: Starting albumart workers Nov 18 11:40:12 cafemusic volumio[870]: Starting albumart workers Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::initPlayerControls Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: Express server listening on port 3000 Nov 18 11:40:12 cafemusic volumio[870]: [Metrics] WebUI: 11s 987.83ms Nov 18 11:40:12 cafemusic volumio-time-update[467]: volumio-time-update-util: Fetching time from Volumio... Nov 18 11:40:12 cafemusic volumio[870]: info: CoreStateMachine::resetVolumioState Nov 18 11:40:12 cafemusic volumio[870]: info: CoreStateMachine::getcurrentVolume Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::volumioRetrievevolume Nov 18 11:40:12 cafemusic ntpd[692]: Listen normally on 3 wlan0 192.168.0.84:123 Nov 18 11:40:12 cafemusic ntpd[692]: new interface(s) found: waking up resolver Nov 18 11:40:12 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 18 11:40:12 cafemusic volumio[870]: info: Volumio Network Manager: Network status updated: 0 Nov 18 11:40:12 cafemusic volumio[870]: info: Cannot mount NAS ServerMusic at system boot, trial number 1 ,retrying in 5 seconds Nov 18 11:40:12 cafemusic volumio[870]: info: Cannot mount NAS Music(Backup) at system boot, trial number 1 ,retrying in 5 seconds Nov 18 11:40:12 cafemusic volumio[870]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Nov 18 11:40:12 cafemusic volumio[870]: wlan0 Interface doesn't support scanning : Device or resource busy Nov 18 11:40:12 cafemusic volumio[870]: info: Cannot use regular scanning, forcing with ap-force Nov 18 11:40:13 cafemusic sudo[1022]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Nov 18 11:40:13 cafemusic sudo[1022]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:14 cafemusic sudo[1022]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:14 cafemusic volumio[870]: info: Reloading queue from file Nov 18 11:40:14 cafemusic volumio[870]: info: VolumeController:: Volume=100 Mute =false Nov 18 11:40:14 cafemusic volumio[870]: info: CoreStateMachine::pushState Nov 18 11:40:14 cafemusic volumio[870]: info: CorePlayQueue::getTrack 0 Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::volumioPushState Nov 18 11:40:14 cafemusic volumio[870]: info: CoreStateMachine::updateTrackBlock Nov 18 11:40:14 cafemusic volumio[870]: info: CorePlayQueue::getTrackBlock Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::volumioRetrievevolume Nov 18 11:40:14 cafemusic volumio[870]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 18 11:40:14 cafemusic volumio[870]: info: USB Boot Capable - System SBC Revision found in cpuinfo: 902120 Nov 18 11:40:14 cafemusic volumio[870]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 18 11:40:14 cafemusic volumio[870]: info: CoreStateMachine::setRepeat true single undefined Nov 18 11:40:14 cafemusic volumio[870]: info: CoreStateMachine::pushState Nov 18 11:40:14 cafemusic volumio[870]: info: CorePlayQueue::getTrack 0 Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::volumioPushState Nov 18 11:40:14 cafemusic volumio[870]: info: CoreStateMachine::setRandom true Nov 18 11:40:14 cafemusic volumio[870]: info: CoreStateMachine::pushState Nov 18 11:40:14 cafemusic volumio[870]: info: CorePlayQueue::getTrack 0 Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::volumioPushState Nov 18 11:40:14 cafemusic volumio[870]: info: Setting Device type: Raspberry PI Nov 18 11:40:14 cafemusic volumio[870]: info: Completed loading Core Plugins Nov 18 11:40:14 cafemusic volumio[870]: info: Preparing to generate the ALSA configuration file Nov 18 11:40:14 cafemusic volumio[870]: info: VolumeController:: Volume=100 Mute =false Nov 18 11:40:14 cafemusic volumio[870]: info: CoreStateMachine::pushState Nov 18 11:40:14 cafemusic volumio[870]: info: CorePlayQueue::getTrack 0 Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::volumioPushState Nov 18 11:40:14 cafemusic volumio[870]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 18 11:40:14 cafemusic volumio[870]: info: Reading ALSA contributions from plugins. Nov 18 11:40:14 cafemusic volumio[870]: info: Asound.conf file unchanged, so no further update is needed Nov 18 11:40:14 cafemusic volumio[870]: info: Output device has changed, restarting MPD Nov 18 11:40:14 cafemusic volumio[870]: info: Output device has changed, restarting Shairport Sync Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 18 11:40:14 cafemusic sudo[1057]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 18 11:40:14 cafemusic sudo[1057]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:14 cafemusic sudo[1057]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:14 cafemusic sudo[1059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 18 11:40:14 cafemusic sudo[1059]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:14 cafemusic nmbd[662]: [2025/11/18 11:40:14.557814, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 18 11:40:14 cafemusic nmbd[662]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Nov 18 11:40:14 cafemusic systemd[1]: Started Samba NMB Daemon. Nov 18 11:40:14 cafemusic volumio[870]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 18 11:40:14 cafemusic volumio[870]: info: ___________ START PLUGINS ___________ Nov 18 11:40:14 cafemusic volumio[870]: info: ControllerMpd::onStart: Initializing MPD Nov 18 11:40:14 cafemusic volumio[870]: info: Creating MPD Configuration file Nov 18 11:40:14 cafemusic systemd[1]: Starting Samba Winbind Daemon... Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 18 11:40:14 cafemusic volumio[870]: info: [1763466014648] CoreMusicLibrary::Adding element Media Servers Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 18 11:40:14 cafemusic sudo[1070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 18 11:40:14 cafemusic sudo[1070]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:14 cafemusic sudo[1068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 18 11:40:14 cafemusic sudo[1068]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:14 cafemusic sudo[1068]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:14 cafemusic systemd[1]: Listening on mpd.socket. Nov 18 11:40:14 cafemusic systemd[1]: Starting Music Player Daemon... Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 18 11:40:14 cafemusic systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Nov 18 11:40:14 cafemusic systemd[1]: mpd.service: Succeeded. Nov 18 11:40:14 cafemusic systemd[1]: Stopped Music Player Daemon. Nov 18 11:40:14 cafemusic systemd[1]: Starting Music Player Daemon... Nov 18 11:40:14 cafemusic volumio[870]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 18 11:40:14 cafemusic volumio[870]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 18 11:40:14 cafemusic volumio[870]: info: [1763466014850] CoreMusicLibrary::Adding element Last_100 Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 18 11:40:14 cafemusic volumio[870]: info: [1763466014854] CoreMusicLibrary::Adding element Webradio Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 18 11:40:14 cafemusic volumio[870]: info: Initializing BBC Radios Nov 18 11:40:14 cafemusic volumio[870]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 18 11:40:14 cafemusic sudo[1078]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 18 11:40:14 cafemusic sudo[1078]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:14 cafemusic sudo[1078]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Nov 18 11:40:14 cafemusic sudo[1078]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 18 11:40:14 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 18 11:40:14 cafemusic volumio[870]: info: AutoStart - onStart Nov 18 11:40:14 cafemusic volumio[870]: info: Loading i18n strings for locale en Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: FusionDsp - mixtype--------------------- Hardware Nov 18 11:40:15 cafemusic volumio[870]: info: Volumio Calling Home Nov 18 11:40:15 cafemusic winbindd[1065]: [2025/11/18 11:40:15.101284, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Nov 18 11:40:15 cafemusic winbindd[1065]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Nov 18 11:40:15 cafemusic volumio[870]: info: Preparing to generate the ALSA configuration file Nov 18 11:40:15 cafemusic winbindd[1065]: [2025/11/18 11:40:15.258187, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 18 11:40:15 cafemusic winbindd[1065]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Nov 18 11:40:15 cafemusic systemd[1]: Started Samba Winbind Daemon. Nov 18 11:40:15 cafemusic volumio[870]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 18 11:40:15 cafemusic volumio[870]: info: Reading ALSA contributions from plugins. Nov 18 11:40:15 cafemusic volumio[870]: info: Volumio Network Manager: Network status updated: 2 Nov 18 11:40:15 cafemusic volumio[870]: info: MPD Permissions set Nov 18 11:40:15 cafemusic volumio[870]: info: MPD Permissions set Nov 18 11:40:15 cafemusic systemd[1]: Starting Samba SMB Daemon... Nov 18 11:40:15 cafemusic volumio[870]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: Starting Shairport Sync Nov 18 11:40:15 cafemusic sudo[1124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 18 11:40:15 cafemusic sudo[1124]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:15 cafemusic sudo[1126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 18 11:40:15 cafemusic sudo[1126]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:15 cafemusic sudo[1126]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:15 cafemusic volumio[870]: info: Starting Shairport Sync Nov 18 11:40:15 cafemusic sudo[1130]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 18 11:40:15 cafemusic sudo[1130]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:15 cafemusic sudo[1124]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:15 cafemusic volumio[870]: info: Starting Shairport Sync Nov 18 11:40:15 cafemusic sudo[1135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 18 11:40:15 cafemusic sudo[1135]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:15 cafemusic sudo[1137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 18 11:40:15 cafemusic sudo[1137]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:15 cafemusic systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 18 11:40:15 cafemusic systemd[1]: shairport-sync.service: Succeeded. Nov 18 11:40:15 cafemusic systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 18 11:40:15 cafemusic volumio[870]: info: Asound.conf file unchanged, so no further update is needed Nov 18 11:40:15 cafemusic volumio[870]: info: Output device has changed, restarting MPD Nov 18 11:40:15 cafemusic volumio[870]: info: Output device has changed, restarting Shairport Sync Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 18 11:40:15 cafemusic sudo[1142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 18 11:40:15 cafemusic sudo[1142]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:15 cafemusic systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 18 11:40:15 cafemusic sudo[1144]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 18 11:40:15 cafemusic sudo[1144]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:15 cafemusic sudo[1142]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:15 cafemusic sudo[1135]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:15 cafemusic sudo[1130]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:15 cafemusic systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 18 11:40:15 cafemusic systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Nov 18 11:40:15 cafemusic systemd[1]: mpd.service: Succeeded. Nov 18 11:40:15 cafemusic systemd[1]: Stopped Music Player Daemon. Nov 18 11:40:15 cafemusic systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Nov 18 11:40:15 cafemusic systemd[1]: shairport-sync.service: Succeeded. Nov 18 11:40:15 cafemusic systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 18 11:40:15 cafemusic volumio[870]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 18 11:40:15 cafemusic volumio[870]: info: MPD Permissions set Nov 18 11:40:15 cafemusic volumio[870]: info: Shairport-Sync Started Nov 18 11:40:15 cafemusic volumio[870]: Error adding Membership: Error: addMembership EINVAL Nov 18 11:40:15 cafemusic volumio[870]: info: Shairport-Sync Started Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:15 cafemusic sudo[1152]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 18 11:40:15 cafemusic sudo[1152]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:15 cafemusic systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 18 11:40:15 cafemusic systemd[1]: Starting Music Player Daemon... Nov 18 11:40:15 cafemusic sudo[1137]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 18 11:40:15 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:16 cafemusic volumio[870]: info: Starting Shairport Sync Nov 18 11:40:16 cafemusic systemd[1]: Started UPnP Renderer front-end to MPD. Nov 18 11:40:16 cafemusic sudo[1160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 18 11:40:16 cafemusic sudo[1152]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:16 cafemusic sudo[1160]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:16 cafemusic volumio[870]: info: Shairport-Sync Started Nov 18 11:40:16 cafemusic volumio[870]: info: Upmpdcli Daemon Started Nov 18 11:40:16 cafemusic systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 18 11:40:16 cafemusic systemd[1]: shairport-sync.service: Succeeded. Nov 18 11:40:16 cafemusic systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 18 11:40:16 cafemusic systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 18 11:40:16 cafemusic sudo[1160]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:16 cafemusic volumio[870]: info: Shairport-Sync Started Nov 18 11:40:16 cafemusic sudo[1158]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 18 11:40:16 cafemusic sudo[1158]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:16 cafemusic sudo[1158]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Nov 18 11:40:16 cafemusic sudo[1158]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:16 cafemusic winbindd[1065]: [2025/11/18 11:40:16.879335, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Nov 18 11:40:16 cafemusic winbindd[1065]: res_names->count = 3, expected 4 Nov 18 11:40:16 cafemusic smbd[1114]: [2025/11/18 11:40:16.941812, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 18 11:40:16 cafemusic smbd[1114]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Nov 18 11:40:16 cafemusic systemd[1]: Started Samba SMB Daemon. Nov 18 11:40:17 cafemusic volumio[870]: info: camilladsp service started and running in background, instance 1 Nov 18 11:40:17 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 18 11:40:17 cafemusic volumio[870]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 <-AAAAAAAAAAAAA Nov 18 11:40:17 cafemusic volumio[870]: info: FusionDsp loaded Nov 18 11:40:17 cafemusic volumio[870]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 18 11:40:17 cafemusic volumio[870]: info: FusionDsp - Reporting Fusion DSP Enabled Nov 18 11:40:17 cafemusic volumio[870]: info: Adding Signal Path Element [object Object] Nov 18 11:40:17 cafemusic volumio[870]: info: Adding fusiondspeq DSP Signal Path Element Nov 18 11:40:17 cafemusic volumio[870]: info: FusionDsp - ---- installed callbackRead Nov 18 11:40:17 cafemusic volumio[870]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 18 11:40:17 cafemusic sudo[1187]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Nov 18 11:40:17 cafemusic sudo[1187]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:17 cafemusic systemd[1]: Started FusionDsp Daemon. Nov 18 11:40:17 cafemusic sudo[1187]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:18 cafemusic sudo[1199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.4/Music(Backup) /mnt/NAS/Music(Backup) Nov 18 11:40:18 cafemusic sudo[1197]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Stephan,password=SG$erv3r,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.3/Storage/Volumio_Music_Files/CafeMusic /mnt/NAS/ServerMusic Nov 18 11:40:18 cafemusic sudo[1199]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:18 cafemusic sudo[1197]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 18 11:40:18 cafemusic kernel: CIFS: Attempting to mount //192.168.0.3/Storage/Volumio_Music_Files/CafeMusic Nov 18 11:40:19 cafemusic volumio-remote-updater[459]: [2025-11-18 11:40:19] [connect] Successful connection Nov 18 11:40:19 cafemusic volumio-remote-updater[459]: [2025-11-18 11:40:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1763466019 101 Nov 18 11:40:19 cafemusic volumio[870]: 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: 2 Nov 18 11:40:22 cafemusic mpd[1168]: Nov 18 11:40 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 18 11:40:22 cafemusic systemd[1]: Started Music Player Daemon. Nov 18 11:40:22 cafemusic volumio[870]: Upnp client error: Error: This socket has been ended by the other party Nov 18 11:40:22 cafemusic sudo[1070]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:22 cafemusic sudo[1059]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:22 cafemusic sudo[1144]: pam_unix(sudo:session): session closed for user root Nov 18 11:40:22 cafemusic volumio[870]: error: MPD error: The expression evaluated to a falsy value: Nov 18 11:40:22 cafemusic volumio[870]: assert.ok(self.idling) Nov 18 11:40:22 cafemusic volumio[870]: error: The expression evaluated to a falsy value: Nov 18 11:40:22 cafemusic volumio[870]: assert.ok(self.idling) Nov 18 11:40:22 cafemusic volumio[870]: info: MPD running with PID1168 Nov 18 11:40:22 cafemusic volumio[870]: ,establishing connection Nov 18 11:40:22 cafemusic volumio[870]: error: MPD error: The expression evaluated to a falsy value: Nov 18 11:40:22 cafemusic volumio[870]: assert.ok(self.idling) Nov 18 11:40:22 cafemusic volumio[870]: error: The expression evaluated to a falsy value: Nov 18 11:40:22 cafemusic volumio[870]: assert.ok(self.idling) Nov 18 11:40:22 cafemusic volumio[870]: error: MPD error: The expression evaluated to a falsy value: Nov 18 11:40:22 cafemusic volumio[870]: assert.ok(self.idling) Nov 18 11:40:22 cafemusic volumio[870]: error: The expression evaluated to a falsy value: Nov 18 11:40:22 cafemusic volumio[870]: assert.ok(self.idling) Nov 18 11:40:22 cafemusic volumio[870]: error: updateQueue error: null Nov 18 11:40:22 cafemusic volumio[870]: [yt-cast-receiver] Listening on port 8098 Nov 18 11:40:22 cafemusic volumio[870]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 18 11:40:22 cafemusic volumio[1162]: Generating RSA private key, 4096 bit long modulus (2 primes) Nov 18 11:40:22 cafemusic volumio[870]: Error: bind EADDRINUSE 192.168.0.84:50352 Nov 18 11:40:22 cafemusic volumio[870]: at dgram.js:337:20 Nov 18 11:40:22 cafemusic volumio[870]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Nov 18 11:40:22 cafemusic volumio[870]: errno: -98, Nov 18 11:40:22 cafemusic volumio[870]: code: 'EADDRINUSE', Nov 18 11:40:22 cafemusic volumio[870]: syscall: 'bind', Nov 18 11:40:22 cafemusic volumio[870]: address: '192.168.0.84', Nov 18 11:40:22 cafemusic volumio[870]: port: 50352 Nov 18 11:40:22 cafemusic volumio[870]: } Nov 18 11:40:22 cafemusic volumio[870]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 18 11:40:23 cafemusic sudo[1232]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-18 11:39 Nov 18 11:40:23 cafemusic sudo[1232]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"