-- Logs begin at Thu 2019-02-14 05:11:58 EST, end at Mon 2025-04-14 15:12:26 EDT. -- Apr 14 15:11:19 volumio-attic fake-hwclock[316]: Mon Apr 14 19:11:19 UTC 2025 Apr 14 15:11:19 volumio-attic systemd[1]: Started Restore / save the current clock. Apr 14 15:11:19 volumio-attic systemd[1]: Started Load/Save Random Seed. Apr 14 15:11:19 volumio-attic systemd[1]: Started Create System Users. Apr 14 15:11:19 volumio-attic systemd[1]: Starting Create Static Device Nodes in /dev... Apr 14 15:11:19 volumio-attic systemd[1]: dynamicswap.service: Succeeded. Apr 14 15:11:19 volumio-attic systemd[1]: Started udev Coldplug all Devices. Apr 14 15:11:19 volumio-attic systemd[1]: Starting Helper to synchronize boot up for ifupdown... Apr 14 15:11:19 volumio-attic systemd[1]: Started Create Static Device Nodes in /dev. Apr 14 15:11:19 volumio-attic systemd[1]: Starting udev Kernel Device Manager... Apr 14 15:11:19 volumio-attic systemd[1]: Reached target Local File Systems (Pre). Apr 14 15:11:19 volumio-attic systemd[1]: Mounting /var/spool/cups... Apr 14 15:11:19 volumio-attic systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Apr 14 15:11:19 volumio-attic systemd[1]: Mounting /tmp... Apr 14 15:11:19 volumio-attic systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Apr 14 15:11:19 volumio-attic systemd[1]: Mounting /var/log... Apr 14 15:11:19 volumio-attic systemd[1]: Started Helper to synchronize boot up for ifupdown. Apr 14 15:11:19 volumio-attic systemd[1]: Mounted /var/spool/cups. Apr 14 15:11:19 volumio-attic systemd[1]: Mounted /tmp. Apr 14 15:11:19 volumio-attic systemd[1]: Mounted /var/log. Apr 14 15:11:19 volumio-attic systemd[1]: Starting Flush Journal to Persistent Storage... Apr 14 15:11:19 volumio-attic systemd[1]: Mounting /var/spool/cups/tmp... Apr 14 15:11:19 volumio-attic systemd-udevd[348]: Network interface NamePolicy= disabled on kernel command line, ignoring. Apr 14 15:11:19 volumio-attic systemd[1]: Mounted /var/spool/cups/tmp. Apr 14 15:11:19 volumio-attic systemd-journald[325]: Runtime journal (/run/log/journal/c1d531165394c79721acb5a765d65e88) is 7.5M, max 30.0M, 22.5M free. Apr 14 15:11:19 volumio-attic systemd[1]: Started Flush Journal to Persistent Storage. Apr 14 15:11:19 volumio-attic systemd[1]: Started udev Kernel Device Manager. Apr 14 15:11:19 volumio-attic systemd[1]: Starting Show Plymouth Boot Screen... Apr 14 15:11:19 volumio-attic systemd[1]: plymouth-start.service: Succeeded. Apr 14 15:11:19 volumio-attic systemd[1]: Started Show Plymouth Boot Screen. Apr 14 15:11:19 volumio-attic systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Apr 14 15:11:19 volumio-attic systemd[1]: Reached target Local Encrypted Volumes. Apr 14 15:11:19 volumio-attic systemd[1]: Reached target Paths. Apr 14 15:11:19 volumio-attic systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Apr 14 15:11:19 volumio-attic systemd-udevd[359]: Using default interface naming scheme 'v240'. Apr 14 15:11:19 volumio-attic kernel: mc: Linux media interface: v0.10 Apr 14 15:11:19 volumio-attic systemd-udevd[372]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 14 15:11:19 volumio-attic kernel: rpi-gpiomem fe200000.gpiomem: window base 0xfe200000 size 0x00001000 Apr 14 15:11:19 volumio-attic kernel: rpi-gpiomem fe200000.gpiomem: initialised 1 regions as /dev/gpiomem Apr 14 15:11:19 volumio-attic systemd-udevd[359]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 14 15:11:19 volumio-attic kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Apr 14 15:11:19 volumio-attic kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Apr 14 15:11:19 volumio-attic kernel: [vc_sm_connected_init]: start Apr 14 15:11:19 volumio-attic kernel: [vc_sm_connected_init]: installed successfully Apr 14 15:11:19 volumio-attic kernel: videodev: Linux video capture interface: v2.00 Apr 14 15:11:19 volumio-attic kernel: input: raspberrypi-ts as /devices/platform/soc/soc:firmware/soc:firmware:touchscreen/input/input0 Apr 14 15:11:19 volumio-attic kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Apr 14 15:11:19 volumio-attic kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Apr 14 15:11:19 volumio-attic kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Apr 14 15:11:19 volumio-attic kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. Apr 14 15:11:19 volumio-attic kernel: rpivid feb10000.codec: Device registered as /dev/video19 Apr 14 15:11:19 volumio-attic kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Apr 14 15:11:19 volumio-attic kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Apr 14 15:11:19 volumio-attic kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Apr 14 15:11:19 volumio-attic kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Apr 14 15:11:19 volumio-attic kernel: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Apr 14 15:11:19 volumio-attic kernel: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Apr 14 15:11:19 volumio-attic kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Apr 14 15:11:19 volumio-attic kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Apr 14 15:11:19 volumio-attic kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Apr 14 15:11:19 volumio-attic kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Apr 14 15:11:19 volumio-attic kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Apr 14 15:11:19 volumio-attic kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Apr 14 15:11:19 volumio-attic kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Apr 14 15:11:19 volumio-attic kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Apr 14 15:11:19 volumio-attic kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Apr 14 15:11:19 volumio-attic kernel: Bluetooth: Core ver 2.22 Apr 14 15:11:19 volumio-attic kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Apr 14 15:11:19 volumio-attic kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Apr 14 15:11:19 volumio-attic kernel: NET: Registered PF_BLUETOOTH protocol family Apr 14 15:11:19 volumio-attic kernel: Bluetooth: HCI device and connection manager initialized Apr 14 15:11:19 volumio-attic kernel: Bluetooth: HCI socket layer initialized Apr 14 15:11:19 volumio-attic kernel: Bluetooth: L2CAP socket layer initialized Apr 14 15:11:19 volumio-attic kernel: Bluetooth: SCO socket layer initialized Apr 14 15:11:19 volumio-attic kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Apr 14 15:11:19 volumio-attic kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Apr 14 15:11:19 volumio-attic kernel: snd-rpi-hifiberry-dacplus soc:sound: activating headphone amplifier Apr 14 15:11:20 volumio-attic kernel: bcm2835_audio bcm2835_audio: card created with 8 channels Apr 14 15:11:20 volumio-attic kernel: Bluetooth: HCI UART driver ver 2.3 Apr 14 15:11:20 volumio-attic kernel: Bluetooth: HCI UART protocol H4 registered Apr 14 15:11:20 volumio-attic kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Apr 14 15:11:20 volumio-attic kernel: Bluetooth: HCI UART protocol Broadcom registered Apr 14 15:11:20 volumio-attic kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Apr 14 15:11:20 volumio-attic kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Apr 14 15:11:20 volumio-attic kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Apr 14 15:11:20 volumio-attic kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Apr 14 15:11:20 volumio-attic kernel: usbcore: registered new interface driver brcmfmac Apr 14 15:11:20 volumio-attic kernel: tpa6130a2 1-0060: supply Vdd not found, using dummy regulator Apr 14 15:11:20 volumio-attic kernel: uart-pl011 fe201000.serial: no DMA platform data Apr 14 15:11:20 volumio-attic systemd-udevd[357]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 14 15:11:20 volumio-attic systemd[1]: Found device /dev/disk/by-uuid/815B-E7CF. Apr 14 15:11:20 volumio-attic kernel: alsactl[510]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set Apr 14 15:11:20 volumio-attic kernel: brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob available (err=-2) Apr 14 15:11:20 volumio-attic 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 14 15:11:20 volumio-attic systemd-udevd[382]: Using default interface naming scheme 'v240'. Apr 14 15:11:20 volumio-attic systemd-udevd[382]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Apr 14 15:11:20 volumio-attic kernel: Bluetooth: hci0: BCM: chip id 107 Apr 14 15:11:20 volumio-attic kernel: Bluetooth: hci0: BCM: features 0x2f Apr 14 15:11:20 volumio-attic kernel: Bluetooth: hci0: BCM4345C0 Apr 14 15:11:20 volumio-attic kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Apr 14 15:11:20 volumio-attic kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Apr 14 15:11:20 volumio-attic systemd[1]: Created slice system-bthelper.slice. Apr 14 15:11:20 volumio-attic systemd[1]: Condition check resulted in Huge Pages File System being skipped. Apr 14 15:11:20 volumio-attic systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Apr 14 15:11:20 volumio-attic systemd-udevd[372]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 14 15:11:20 volumio-attic systemd[1]: Starting Show Plymouth Boot Screen... Apr 14 15:11:20 volumio-attic systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Apr 14 15:11:20 volumio-attic systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Apr 14 15:11:20 volumio-attic systemd[1]: Starting File System Check on /dev/disk/by-uuid/815B-E7CF... Apr 14 15:11:20 volumio-attic systemd[1]: Created slice system-systemd\x2dbacklight.slice. Apr 14 15:11:20 volumio-attic systemd[1]: Starting Load/Save Screen Backlight Brightness of backlight:rpi_backlight... Apr 14 15:11:20 volumio-attic systemd[1]: Found device /sys/subsystem/net/devices/eth0. Apr 14 15:11:20 volumio-attic systemd[1]: plymouth-start.service: Succeeded. Apr 14 15:11:20 volumio-attic systemd[1]: Started Show Plymouth Boot Screen. Apr 14 15:11:20 volumio-attic systemd[1]: Started Load/Save Screen Backlight Brightness of backlight:rpi_backlight. Apr 14 15:11:20 volumio-attic systemd[1]: Started File System Check Daemon to report status. Apr 14 15:11:20 volumio-attic systemd[1]: Starting Load/Save RF Kill Switch Status... Apr 14 15:11:20 volumio-attic systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Apr 14 15:11:20 volumio-attic systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Apr 14 15:11:20 volumio-attic systemd[1]: Started Load/Save RF Kill Switch Status. Apr 14 15:11:20 volumio-attic systemd-fsck[540]: fsck.fat 4.1 (2017-01-24) Apr 14 15:11:20 volumio-attic systemd-fsck[540]: /dev/mmcblk0p1: 411 files, 41753/46774 clusters Apr 14 15:11:20 volumio-attic systemd[1]: Started File System Check on /dev/disk/by-uuid/815B-E7CF. Apr 14 15:11:20 volumio-attic systemd[1]: Mounting /boot... Apr 14 15:11:20 volumio-attic systemd[1]: Mounted /boot. Apr 14 15:11:20 volumio-attic systemd[1]: Reached target Local File Systems. Apr 14 15:11:20 volumio-attic systemd[1]: Started ifup for wlan0. Apr 14 15:11:20 volumio-attic systemd[1]: Starting Raise network interfaces... Apr 14 15:11:20 volumio-attic systemd[1]: Starting Create Volatile Files and Directories... Apr 14 15:11:20 volumio-attic systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Apr 14 15:11:20 volumio-attic systemd[1]: Starting Preprocess NFS configuration... Apr 14 15:11:20 volumio-attic systemd[1]: Started ifup for eth0. Apr 14 15:11:20 volumio-attic systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Apr 14 15:11:20 volumio-attic systemd[1]: nfs-config.service: Succeeded. Apr 14 15:11:20 volumio-attic systemd[1]: Started Preprocess NFS configuration. Apr 14 15:11:20 volumio-attic systemd[1]: plymouth-read-write.service: Succeeded. Apr 14 15:11:20 volumio-attic systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Apr 14 15:11:20 volumio-attic systemd[1]: Received SIGRTMIN+20 from PID 208 (plymouthd). Apr 14 15:11:20 volumio-attic systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Apr 14 15:11:20 volumio-attic systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Apr 14 15:11:20 volumio-attic systemd[1]: Reached target NFS client services. Apr 14 15:11:20 volumio-attic systemd[1]: Started Create Volatile Files and Directories. Apr 14 15:11:20 volumio-attic systemd[1]: Starting RPC bind portmap service... Apr 14 15:11:20 volumio-attic kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211 Apr 14 15:11:20 volumio-attic systemd[1]: Starting Update UTMP about System Boot/Shutdown... Apr 14 15:11:20 volumio-attic systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Apr 14 15:11:20 volumio-attic systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Apr 14 15:11:20 volumio-attic systemd[1]: Started Update UTMP about System Boot/Shutdown. Apr 14 15:11:20 volumio-attic systemd[1]: Reached target System Initialization. Apr 14 15:11:20 volumio-attic systemd[1]: Listening on triggerhappy.socket. Apr 14 15:11:20 volumio-attic systemd[1]: Started Daily man-db regeneration. Apr 14 15:11:20 volumio-attic systemd[1]: Started Daily Cleanup of Temporary Directories. Apr 14 15:11:20 volumio-attic systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Apr 14 15:11:20 volumio-attic systemd[1]: Listening on D-Bus System Message Bus Socket. Apr 14 15:11:20 volumio-attic systemd[1]: Reached target Sockets. Apr 14 15:11:20 volumio-attic systemd[1]: Reached target Basic System. Apr 14 15:11:20 volumio-attic systemd[1]: Starting triggerhappy global hotkey daemon... Apr 14 15:11:20 volumio-attic systemd[1]: Started Manage Sound Card State (restore and store). Apr 14 15:11:20 volumio-attic kernel: 8021q: 802.1Q VLAN Support v1.8 Apr 14 15:11:20 volumio-attic alsactl[628]: alsactl 1.1.8 daemon started Apr 14 15:11:20 volumio-attic systemd[1]: Starting Save/Restore Sound Card State... Apr 14 15:11:20 volumio-attic thd[624]: Unable to parse trigger line: Apr 14 15:11:20 volumio-attic thd[624]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Apr 14 15:11:20 volumio-attic thd[624]: Unable to parse trigger line: Apr 14 15:11:20 volumio-attic thd[624]: Found socket passed from systemd Apr 14 15:11:20 volumio-attic systemd[1]: Started MPD Monitor Service. Apr 14 15:11:20 volumio-attic mpd_monitor.sh[630]: MPD Monitor Service: Starting MPD Monitor Service Apr 14 15:11:20 volumio-attic systemd[1]: Started volumio-remote-updater.service. Apr 14 15:11:20 volumio-attic systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Apr 14 15:11:20 volumio-attic kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 14 15:11:20 volumio-attic systemd[1]: Starting Volumio Time Update Utility... Apr 14 15:11:20 volumio-attic systemd[1]: Starting Configure Bluetooth Modems connected by UART... Apr 14 15:11:20 volumio-attic systemd[1]: Starting Login Service... Apr 14 15:11:20 volumio-attic volumio-time-update[633]: volumio-time-update-util: Fetching time from Volumio... Apr 14 15:11:20 volumio-attic systemd[1]: Started D-Bus System Message Bus. Apr 14 15:11:20 volumio-attic systemd[1]: Starting WPA supplicant... Apr 14 15:11:20 volumio-attic systemd[1]: Started UPnP Renderer front-end to MPD. Apr 14 15:11:20 volumio-attic systemd[1]: Started Volumio Log Rotation Service. Apr 14 15:11:20 volumio-attic systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Apr 14 15:11:20 volumio-attic systemd[1]: Starting dhcpcd on all interfaces... Apr 14 15:11:21 volumio-attic systemd[1]: Starting Wireless Services... Apr 14 15:11:21 volumio-attic systemd[1]: Started Daily apt download activities. Apr 14 15:11:21 volumio-attic systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Apr 14 15:11:21 volumio-attic systemd[1]: Reached target Login Prompts. Apr 14 15:11:21 volumio-attic systemd[1]: Started Daily apt upgrade and clean activities. Apr 14 15:11:21 volumio-attic systemd[1]: Reached target Timers. Apr 14 15:11:21 volumio-attic systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Apr 14 15:11:21 volumio-attic systemd[1]: Started Volumio Iptables Module. Apr 14 15:11:21 volumio-attic systemd[1]: Started triggerhappy global hotkey daemon. Apr 14 15:11:21 volumio-attic systemd[1]: Started RPC bind portmap service. Apr 14 15:11:21 volumio-attic systemd[1]: Started Save/Restore Sound Card State. Apr 14 15:11:21 volumio-attic systemd[1]: Reached target Sound Card. Apr 14 15:11:21 volumio-attic systemd[1]: Reached target Remote File Systems (Pre). Apr 14 15:11:21 volumio-attic systemd[1]: Reached target Remote File Systems. Apr 14 15:11:21 volumio-attic systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Apr 14 15:11:21 volumio-attic systemd[1]: Reached target RPC Port Mapper. Apr 14 15:11:21 volumio-attic dhcpcd[660]: Not running dhcpcd because /etc/network/interfaces Apr 14 15:11:21 volumio-attic dhcpcd[660]: defines some interfaces that will use a Apr 14 15:11:21 volumio-attic dhcpcd[660]: DHCP client or static address Apr 14 15:11:21 volumio-attic systemd-logind[640]: New seat seat0. Apr 14 15:11:21 volumio-attic mpd_monitor.sh[630]: MPD error: Connection refused Apr 14 15:11:21 volumio-attic mpd_monitor.sh[630]: MPD Monitor Service: MPD Appears to be inactive, restarting Apr 14 15:11:21 volumio-attic kernel: Bluetooth: hci0: BCM: features 0x2f Apr 14 15:11:21 volumio-attic kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Apr 14 15:11:21 volumio-attic kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Apr 14 15:11:21 volumio-attic mpd_monitor.sh[630]: mpd: no process found Apr 14 15:11:21 volumio-attic avahi-daemon[671]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Apr 14 15:11:21 volumio-attic avahi-daemon[671]: Successfully dropped root privileges. Apr 14 15:11:21 volumio-attic avahi-daemon[671]: avahi-daemon 0.7 starting up. Apr 14 15:11:21 volumio-attic sh[561]: eth0: waiting for carrier Apr 14 15:11:21 volumio-attic dhcpcd[609]: eth0: waiting for carrier Apr 14 15:11:21 volumio-attic kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Apr 14 15:11:21 volumio-attic kernel: bcmgenet fd580000.ethernet eth0: Link is Down Apr 14 15:11:21 volumio-attic avahi-daemon[671]: Successfully called chroot(). Apr 14 15:11:21 volumio-attic avahi-daemon[671]: Successfully dropped remaining capabilities. Apr 14 15:11:21 volumio-attic wpa_supplicant[654]: Successfully initialized wpa_supplicant Apr 14 15:11:21 volumio-attic systemd[1]: Started Avahi mDNS/DNS-SD Stack. Apr 14 15:11:21 volumio-attic systemd[1]: Started WPA supplicant. Apr 14 15:11:21 volumio-attic avahi-daemon[671]: Loading service file /services/volumio.service. Apr 14 15:11:21 volumio-attic systemd[1]: Started Login Service. Apr 14 15:11:21 volumio-attic systemd[1]: hciuart.service: Succeeded. Apr 14 15:11:21 volumio-attic systemd[1]: Started Configure Bluetooth Modems connected by UART. Apr 14 15:11:21 volumio-attic systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Apr 14 15:11:21 volumio-attic systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Apr 14 15:11:21 volumio-attic systemd[1]: Failed to start dhcpcd on all interfaces. Apr 14 15:11:21 volumio-attic avahi-daemon[671]: Network interface enumeration completed. Apr 14 15:11:21 volumio-attic avahi-daemon[671]: Server startup complete. Host name is volumio-attic.local. Local service cookie is 27307527. Apr 14 15:11:21 volumio-attic avahi-daemon[671]: Service "Volumio attic" (/services/volumio.service) successfully established. Apr 14 15:11:21 volumio-attic volumio-remote-updater[631]: Error: No active session Apr 14 15:11:21 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:11:21] [info] asio async_connect error: system:111 (Connection refused) Apr 14 15:11:21 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:11:21] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 14 15:11:21 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:11:21] [error] handle_connect error: Underlying Transport Error Apr 14 15:11:21 volumio-attic sh[551]: wlan0=wlan0 Apr 14 15:11:21 volumio-attic volumio[658]: Could not open config: /tmp/upmpdcli.conf Apr 14 15:11:21 volumio-attic volumio-time-update[633]: volumio-time-update-util: Date not found in response Apr 14 15:11:21 volumio-attic volumio-time-update[633]: volumio-time-update-util: Retrying in 5 seconds... Apr 14 15:11:21 volumio-attic systemd[1]: Listening on mpd.socket. Apr 14 15:11:21 volumio-attic systemd[1]: Starting Raspberry Pi bluetooth helper... Apr 14 15:11:21 volumio-attic systemd[1]: Started Raise network interfaces. Apr 14 15:11:21 volumio-attic systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 14 15:11:21 volumio-attic systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 14 15:11:21 volumio-attic systemd[1]: Reached target Network. Apr 14 15:11:21 volumio-attic systemd[1]: Starting Network Time Service... Apr 14 15:11:21 volumio-attic systemd[1]: Starting Permit User Sessions... Apr 14 15:11:21 volumio-attic systemd[1]: Reached target Network is Online. Apr 14 15:11:21 volumio-attic systemd[1]: Starting LSB: Brings up/down network automatically... Apr 14 15:11:21 volumio-attic systemd[1]: Starting Samba NMB Daemon... Apr 14 15:11:21 volumio-attic systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Apr 14 15:11:21 volumio-attic systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 14 15:11:21 volumio-attic systemd[1]: Starting /etc/rc.local Compatibility... Apr 14 15:11:21 volumio-attic systemd[1]: Starting Music Player Daemon... Apr 14 15:11:21 volumio-attic bthelper[755]: Raspberry Pi BDADDR already set Apr 14 15:11:22 volumio-attic loadcpufreq[674]: Loading cpufreq kernel modules...done (none). Apr 14 15:11:22 volumio-attic systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Apr 14 15:11:22 volumio-attic systemd[1]: Started Raspberry Pi bluetooth helper. Apr 14 15:11:22 volumio-attic systemd[1]: Started Permit User Sessions. Apr 14 15:11:22 volumio-attic systemd[1]: Started /etc/rc.local Compatibility. Apr 14 15:11:22 volumio-attic systemd[1]: iptables.service: Succeeded. Apr 14 15:11:22 volumio-attic systemd[1]: Starting Terminate Plymouth Boot Screen... Apr 14 15:11:22 volumio-attic systemd[1]: Starting Hold until boot process finishes up... Apr 14 15:11:22 volumio-attic systemd[1]: Starting Bluetooth service... Apr 14 15:11:22 volumio-attic systemd[1]: Starting LSB: set CPUFreq kernel parameters... Apr 14 15:11:22 volumio-attic haveged[596]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Apr 14 15:11:22 volumio-attic haveged[596]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Apr 14 15:11:22 volumio-attic haveged[596]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00119 Apr 14 15:11:22 volumio-attic haveged[596]: haveged: fills: 0, generated: 0 Apr 14 15:11:22 volumio-attic systemd[1]: plymouth-quit.service: Succeeded. Apr 14 15:11:22 volumio-attic systemd[1]: Started Terminate Plymouth Boot Screen. Apr 14 15:11:22 volumio-attic systemd[1]: plymouth-quit-wait.service: Succeeded. Apr 14 15:11:22 volumio-attic systemd[1]: Started Hold until boot process finishes up. Apr 14 15:11:22 volumio-attic systemd[1]: Received SIGRTMIN+21 from PID 208 (n/a). Apr 14 15:11:22 volumio-attic systemd[1]: Received SIGRTMIN+21 from PID 208 (n/a). Apr 14 15:11:22 volumio-attic ifplugd(eth0)[813]: ifplugd 0.28 initializing. Apr 14 15:11:22 volumio-attic ifplugd(eth0)[813]: Using interface eth0/E4:5F:01:AE:37:F1 with driver (version: 6.6.62-v7l+) Apr 14 15:11:22 volumio-attic ifplugd(eth0)[813]: Using detection mode: SIOCETHTOOL Apr 14 15:11:22 volumio-attic ifplugd(eth0)[813]: Initialization complete, link beat not detected. Apr 14 15:11:22 volumio-attic cpufrequtils[800]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Apr 14 15:11:22 volumio-attic systemd[1]: Started LSB: set CPUFreq kernel parameters. Apr 14 15:11:22 volumio-attic ntpd[765]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 14 15:11:22 volumio-attic ntpd[765]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Apr 14 15:11:22 volumio-attic systemd[1]: Started Network Time Service. Apr 14 15:11:22 volumio-attic ifplugd[771]: Network Interface Plugging Daemon...start eth0...done. Apr 14 15:11:22 volumio-attic ntpd[830]: proto: precision = 0.815 usec (-20) Apr 14 15:11:22 volumio-attic systemd[1]: Started LSB: Brings up/down network automatically. Apr 14 15:11:22 volumio-attic ntpd[830]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 14 15:11:22 volumio-attic ntpd[830]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 14 15:11:22 volumio-attic ntpd[830]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 108 days ago Apr 14 15:11:22 volumio-attic ntpd[830]: Listen and drop on 0 v6wildcard [::]:123 Apr 14 15:11:22 volumio-attic ntpd[830]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 14 15:11:22 volumio-attic ntpd[830]: Listen normally on 2 lo 127.0.0.1:123 Apr 14 15:11:22 volumio-attic ntpd[830]: Listening on routing socket on fd #19 for interface updates Apr 14 15:11:22 volumio-attic ntpd[830]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 15:11:22 volumio-attic ntpd[830]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 14 15:11:22 volumio-attic bluetoothd[799]: Bluetooth daemon 5.50 Apr 14 15:11:22 volumio-attic bluetoothd[799]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Apr 14 15:11:22 volumio-attic systemd[1]: Started Bluetooth service. Apr 14 15:11:22 volumio-attic systemd[1]: Reached target Bluetooth. Apr 14 15:11:22 volumio-attic bluetoothd[799]: Starting SDP server Apr 14 15:11:22 volumio-attic bluetoothd[799]: Excluding (cli) sap Apr 14 15:11:22 volumio-attic kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Apr 14 15:11:22 volumio-attic kernel: Bluetooth: BNEP filters: protocol multicast Apr 14 15:11:22 volumio-attic kernel: Bluetooth: BNEP socket layer initialized Apr 14 15:11:22 volumio-attic bluetoothd[799]: Bluetooth management interface 1.22 initialized Apr 14 15:11:22 volumio-attic dbus-daemon[642]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=799 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Apr 14 15:11:22 volumio-attic kernel: Bluetooth: MGMT ver 1.22 Apr 14 15:11:22 volumio-attic sudo[785]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 15:11:22 volumio-attic sudo[785]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:22 volumio-attic sudo[785]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 14 15:11:22 volumio-attic sudo[785]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:22 volumio-attic bluetoothd[799]: Failed to set privacy: Rejected (0x0b) Apr 14 15:11:22 volumio-attic systemd[1]: Starting Hostname Service... Apr 14 15:11:22 volumio-attic dbus-daemon[642]: [system] Successfully activated service 'org.freedesktop.hostname1' Apr 14 15:11:22 volumio-attic systemd[1]: Started Hostname Service. Apr 14 15:11:23 volumio-attic nmbd[788]: [2025/04/14 15:11:23.096085, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Apr 14 15:11:23 volumio-attic nmbd[788]: started asyncdns process 837 Apr 14 15:11:23 volumio-attic nmbd[788]: [2025/04/14 15:11:23.111005, 0] ../lib/util/become_daemon.c:149(daemon_status) Apr 14 15:11:23 volumio-attic nmbd[788]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Apr 14 15:11:23 volumio-attic nmbd[788]: [2025/04/14 15:11:23.111462, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Apr 14 15:11:23 volumio-attic nmbd[788]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Apr 14 15:11:23 volumio-attic wireless.js[664]: Cleaning previous... Apr 14 15:11:23 volumio-attic ntpd[830]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 14 15:11:23 volumio-attic sudo[845]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 14 15:11:23 volumio-attic sudo[845]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:23 volumio-attic sudo[845]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:23 volumio-attic sudo[847]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 14 15:11:23 volumio-attic sudo[847]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:23 volumio-attic sudo[847]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:23 volumio-attic wireless.js[664]: Stopped aP Apr 14 15:11:24 volumio-attic sudo[854]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 14 15:11:24 volumio-attic sudo[854]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:24 volumio-attic sudo[854]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:24 volumio-attic kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 14 15:11:24 volumio-attic sudo[856]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Apr 14 15:11:24 volumio-attic sudo[856]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:24 volumio-attic sudo[856]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:24 volumio-attic sudo[863]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 14 15:11:24 volumio-attic sudo[863]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:24 volumio-attic sudo[863]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:24 volumio-attic sudo[865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Apr 14 15:11:24 volumio-attic sudo[865]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:24 volumio-attic ntpd[830]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 14 15:11:24 volumio-attic mpd[834]: Apr 14 15:11 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 15:11:25 volumio-attic ntpd[830]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 14 15:11:25 volumio-attic systemd[1]: systemd-rfkill.service: Succeeded. Apr 14 15:11:26 volumio-attic ntpd[830]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 14 15:11:26 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:11:26] [info] asio async_connect error: system:111 (Connection refused) Apr 14 15:11:26 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:11:26] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 14 15:11:26 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:11:26] [error] handle_connect error: Underlying Transport Error Apr 14 15:11:26 volumio-attic volumio-time-update[633]: volumio-time-update-util: Fetching time from Volumio... Apr 14 15:11:26 volumio-attic volumio-time-update[633]: volumio-time-update-util: Date not found in response Apr 14 15:11:26 volumio-attic volumio-time-update[633]: volumio-time-update-util: Retrying in 5 seconds... Apr 14 15:11:26 volumio-attic sudo[865]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:26 volumio-attic wireless.js[664]: SETTING APPROPRIATE REG DOMAIN: US Apr 14 15:11:26 volumio-attic sudo[875]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 14 15:11:26 volumio-attic sudo[875]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:26 volumio-attic sudo[875]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:26 volumio-attic sudo[877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set US Apr 14 15:11:26 volumio-attic sudo[877]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:26 volumio-attic sudo[877]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:26 volumio-attic wireless.js[664]: SUCCESSFULLY SET NEW REGDOMAIN: US Apr 14 15:11:26 volumio-attic systemd[1]: Started Music Player Daemon. Apr 14 15:11:26 volumio-attic wireless.js[664]: Start wireless flow Apr 14 15:11:26 volumio-attic wireless.js[664]: Stopped hotspot (if there).. Apr 14 15:11:26 volumio-attic mpd_monitor.sh[630]: MPD Monitor Service: MPD restarted due to no mpc output. Apr 14 15:11:26 volumio-attic sudo[885]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 14 15:11:26 volumio-attic sudo[885]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:26 volumio-attic sudo[885]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:27 volumio-attic sudo[887]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 14 15:11:27 volumio-attic sudo[887]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:27 volumio-attic bthelper[755]: Changing power off succeeded Apr 14 15:11:27 volumio-attic bthelper[755]: [CHG] Controller E4:5F:01:AE:37:F5 Class: 0x0000041c Apr 14 15:11:27 volumio-attic bthelper[755]: Changing power on succeeded Apr 14 15:11:27 volumio-attic sudo[887]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:27 volumio-attic wireless.js[664]: DHCP IP Apr 14 15:11:27 volumio-attic wireless.js[664]: Start ap Apr 14 15:11:27 volumio-attic wpa_supplicant[897]: Successfully initialized wpa_supplicant Apr 14 15:11:27 volumio-attic sudo[898]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Apr 14 15:11:27 volumio-attic sudo[898]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:27 volumio-attic dhcpcd[899]: dev: loaded udev Apr 14 15:11:27 volumio-attic kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 14 15:11:27 volumio-attic dhcpcd-run-hooks[917]: wlan0: starting wpa_supplicant Apr 14 15:11:27 volumio-attic dhcpcd-run-hooks[922]: wlan0: failed to start wpa_supplicant Apr 14 15:11:27 volumio-attic dhcpcd-run-hooks[923]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Apr 14 15:11:27 volumio-attic dhcpcd[899]: wlan0: connected to Access Point `' Apr 14 15:11:27 volumio-attic dhcpcd[899]: no interfaces have a carrier Apr 14 15:11:27 volumio-attic dhcpcd[899]: forked to background, child pid 933 Apr 14 15:11:27 volumio-attic dhcpcd[933]: eth0: waiting for carrier Apr 14 15:11:27 volumio-attic dhcpcd[933]: wlan0: waiting for carrier Apr 14 15:11:27 volumio-attic sudo[898]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:28 volumio-attic wireless.js[664]: trying... Apr 14 15:11:28 volumio-attic sudo[935]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:28 volumio-attic sudo[935]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:28 volumio-attic sudo[935]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:29 volumio-attic wireless.js[664]: trying... Apr 14 15:11:29 volumio-attic sudo[938]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:29 volumio-attic sudo[938]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:29 volumio-attic sudo[938]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:30 volumio-attic wireless.js[664]: trying... Apr 14 15:11:30 volumio-attic sudo[941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:30 volumio-attic sudo[941]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:30 volumio-attic sudo[941]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:31 volumio-attic wireless.js[664]: trying... Apr 14 15:11:31 volumio-attic sudo[944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:31 volumio-attic sudo[944]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:31 volumio-attic sudo[944]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:31 volumio-attic kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Apr 14 15:11:31 volumio-attic kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Apr 14 15:11:31 volumio-attic volumio-time-update[633]: volumio-time-update-util: Fetching time from Volumio... Apr 14 15:11:31 volumio-attic volumio-time-update[633]: volumio-time-update-util: Date not found in response Apr 14 15:11:31 volumio-attic volumio-time-update[633]: volumio-time-update-util: Retrying in 5 seconds... Apr 14 15:11:31 volumio-attic kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Apr 14 15:11:32 volumio-attic kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Apr 14 15:11:32 volumio-attic wireless.js[664]: trying... Apr 14 15:11:32 volumio-attic sudo[952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:32 volumio-attic sudo[952]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:32 volumio-attic sudo[952]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:33 volumio-attic wireless.js[664]: trying... Apr 14 15:11:33 volumio-attic sudo[955]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:33 volumio-attic sudo[955]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:33 volumio-attic sudo[955]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:34 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:11:34] [info] asio async_connect error: system:111 (Connection refused) Apr 14 15:11:34 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:11:34] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Apr 14 15:11:34 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:11:34] [error] handle_connect error: Underlying Transport Error Apr 14 15:11:34 volumio-attic wpa_supplicant[921]: wlan0: Trying to associate with SSID 'FiOS-F3FXZ' Apr 14 15:11:34 volumio-attic wireless.js[664]: trying... Apr 14 15:11:34 volumio-attic sudo[958]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:34 volumio-attic sudo[958]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:34 volumio-attic dhcpcd[933]: wlan0: carrier acquired Apr 14 15:11:34 volumio-attic dhcpcd[933]: wlan0: connected to Access Point `FiOS-F3FXZ' Apr 14 15:11:34 volumio-attic wpa_supplicant[921]: wlan0: Associated with 84:16:f9:fc:c2:66 Apr 14 15:11:34 volumio-attic wpa_supplicant[921]: wlan0: CTRL-EVENT-CONNECTED - Connection to 84:16:f9:fc:c2:66 completed [id=0 id_str=] Apr 14 15:11:34 volumio-attic wpa_supplicant[921]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 14 15:11:34 volumio-attic sudo[958]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:34 volumio-attic dhcpcd[933]: DUID 00:01:00:01:2d:69:1d:d1:e4:5f:01:ae:37:f3 Apr 14 15:11:34 volumio-attic dhcpcd[933]: wlan0: IAID 01:ae:37:f3 Apr 14 15:11:34 volumio-attic dhcpcd[933]: wlan0: adding address fe80::e521:eef8:40ee:6c02 Apr 14 15:11:34 volumio-attic dhcpcd[933]: ipv6_addaddr1: Permission denied Apr 14 15:11:34 volumio-attic dhcpcd[933]: wlan0: carrier lost Apr 14 15:11:34 volumio-attic dhcpcd[933]: wlan0: carrier acquired Apr 14 15:11:34 volumio-attic dhcpcd[933]: wlan0: IAID 01:ae:37:f3 Apr 14 15:11:34 volumio-attic dhcpcd[933]: wlan0: rebinding lease of 192.168.1.65 Apr 14 15:11:34 volumio-attic dhcpcd[933]: wlan0: probing address 192.168.1.65/24 Apr 14 15:11:35 volumio-attic wireless.js[664]: trying... Apr 14 15:11:35 volumio-attic dhcpcd[933]: wlan0: soliciting an IPv6 router Apr 14 15:11:35 volumio-attic sudo[973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:35 volumio-attic sudo[973]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:35 volumio-attic sudo[973]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:36 volumio-attic wireless.js[664]: trying... Apr 14 15:11:36 volumio-attic sudo[976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:36 volumio-attic sudo[976]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:36 volumio-attic sudo[976]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:36 volumio-attic volumio-time-update[633]: volumio-time-update-util: Fetching time from Volumio... Apr 14 15:11:36 volumio-attic volumio-time-update[633]: volumio-time-update-util: Date not found in response Apr 14 15:11:36 volumio-attic volumio-time-update[633]: volumio-time-update-util: Retrying in 5 seconds... Apr 14 15:11:37 volumio-attic wireless.js[664]: trying... Apr 14 15:11:37 volumio-attic sudo[984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:37 volumio-attic sudo[984]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:37 volumio-attic sudo[984]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:38 volumio-attic wireless.js[664]: trying... Apr 14 15:11:38 volumio-attic sudo[987]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:38 volumio-attic sudo[987]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:38 volumio-attic sudo[987]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:39 volumio-attic wireless.js[664]: trying... Apr 14 15:11:39 volumio-attic sudo[990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:39 volumio-attic sudo[990]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:39 volumio-attic sudo[990]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:40 volumio-attic dhcpcd[933]: wlan0: leased 192.168.1.65 for 86400 seconds Apr 14 15:11:40 volumio-attic avahi-daemon[671]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.65. Apr 14 15:11:40 volumio-attic avahi-daemon[671]: New relevant interface wlan0.IPv4 for mDNS. Apr 14 15:11:40 volumio-attic avahi-daemon[671]: Registering new address record for 192.168.1.65 on wlan0.IPv4. Apr 14 15:11:40 volumio-attic dhcpcd[933]: wlan0: adding route to 192.168.1.0/24 Apr 14 15:11:40 volumio-attic dhcpcd[933]: wlan0: adding default route via 192.168.1.1 Apr 14 15:11:40 volumio-attic wireless.js[664]: trying... Apr 14 15:11:40 volumio-attic sudo[1014]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 14 15:11:40 volumio-attic sudo[1014]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:40 volumio-attic sudo[1014]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:40 volumio-attic wireless.js[664]: Connected to: ----FiOS-F3FXZ Apr 14 15:11:40 volumio-attic wireless.js[664]: ---- Apr 14 15:11:40 volumio-attic sudo[1017]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 15:11:40 volumio-attic sudo[1017]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:40 volumio-attic sudo[1017]: pam_unix(sudo:session): session closed for user root Apr 14 15:11:40 volumio-attic wireless.js[664]: ... joined AP, wlan0 IPv4 is 192.168.1.65, ipV6 is undefined Apr 14 15:11:40 volumio-attic wireless.js[664]: It's done! AP Apr 14 15:11:40 volumio-attic kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 14 15:11:40 volumio-attic systemd[1]: Started Wireless Services. Apr 14 15:11:40 volumio-attic systemd[1]: Started Volumio Backend Module. Apr 14 15:11:40 volumio-attic systemd[1]: Started Volumio Cpu Tweaker. Apr 14 15:11:40 volumio-attic volumio-cpu-tweak[1023]: Setting RT Priority for mpd Apr 14 15:11:40 volumio-attic volumio-cpu-tweak[1023]: Setting MPD Affinity Apr 14 15:11:40 volumio-attic volumio-cpu-tweak[1023]: pid 834's current affinity mask: f Apr 14 15:11:40 volumio-attic volumio-cpu-tweak[1023]: pid 834's new affinity mask: 3 Apr 14 15:11:40 volumio-attic volumio-cpu-tweak[1023]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Apr 14 15:11:40 volumio-attic volumio-cpu-tweak[1023]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Apr 14 15:11:40 volumio-attic systemd[1]: volumio_cpu_tweak.service: Succeeded. Apr 14 15:11:41 volumio-attic ntpd[830]: Listen normally on 3 wlan0 192.168.1.65:123 Apr 14 15:11:41 volumio-attic ntpd[830]: new interface(s) found: waking up resolver Apr 14 15:11:41 volumio-attic volumio-time-update[633]: volumio-time-update-util: Fetching time from Volumio... Apr 14 15:11:42 volumio-attic volumio-time-update[633]: volumio-time-update-util: Setting system time to: 2025-04-14 15:12:10 Apr 14 15:11:42 volumio-attic sudo[1052]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-04-14 15:12:10 Apr 14 15:11:42 volumio-attic sudo[1052]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:11:42 volumio-attic dbus-daemon[642]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.9' (uid=0 pid=1053 comm="timedatectl set-time 2025-04-14 15:12:10 ") Apr 14 15:11:42 volumio-attic volumio[1022]: info: ------------------------------------------- Apr 14 15:11:42 volumio-attic volumio[1022]: info: ----- Volumio3 ---- Apr 14 15:11:42 volumio-attic volumio[1022]: info: ------------------------------------------- Apr 14 15:11:42 volumio-attic volumio[1022]: info: ----- System startup ---- Apr 14 15:11:42 volumio-attic volumio[1022]: info: ------------------------------------------- Apr 14 15:11:42 volumio-attic systemd[1]: Starting Time & Date Service... Apr 14 15:11:42 volumio-attic dbus-daemon[642]: [system] Successfully activated service 'org.freedesktop.timedate1' Apr 14 15:11:42 volumio-attic systemd[1]: Started Time & Date Service. Apr 14 15:12:10 volumio-attic systemd-timedated[1054]: Changed local time to Mon Apr 14 15:12:10 2025 Apr 14 15:12:10 volumio-attic sudo[1052]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:10 volumio-attic volumio-time-update[633]: volumio-time-update-util: System time updated successfully. Apr 14 15:12:10 volumio-attic systemd[1]: Started Volumio Time Update Utility. Apr 14 15:12:10 volumio-attic volumio[1022]: info: MYVOLUMIO Environment detected Apr 14 15:12:10 volumio-attic volumio[1022]: info: Plugin folders cleanup Apr 14 15:12:10 volumio-attic volumio[1022]: info: Scanning into folder /volumio/app/plugins/ Apr 14 15:12:10 volumio-attic volumio[1022]: info: Scanning category audio_interface Apr 14 15:12:10 volumio-attic volumio[1022]: info: Scanning category miscellanea Apr 14 15:12:10 volumio-attic volumio[1022]: info: Scanning category music_service Apr 14 15:12:10 volumio-attic volumio[1022]: info: Scanning category plugins.json Apr 14 15:12:10 volumio-attic volumio[1022]: info: Scanning category system_controller Apr 14 15:12:10 volumio-attic volumio[1022]: info: Scanning category user_interface Apr 14 15:12:10 volumio-attic volumio[1022]: info: Scanning into folder /data/plugins/ Apr 14 15:12:10 volumio-attic volumio[1022]: info: Scanning category music_service Apr 14 15:12:10 volumio-attic volumio[1022]: info: Scanning category user_interface Apr 14 15:12:10 volumio-attic volumio[1022]: info: Plugin folders cleanup completed Apr 14 15:12:10 volumio-attic volumio[1022]: info: ------------------------------------------- Apr 14 15:12:10 volumio-attic volumio[1022]: info: ----- Core plugins startup ---- Apr 14 15:12:10 volumio-attic volumio[1022]: info: ------------------------------------------- Apr 14 15:12:10 volumio-attic volumio[1022]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 15:12:10 volumio-attic volumio[1022]: info: Adding plugin upnp to MyMusic Plugins Apr 14 15:12:10 volumio-attic volumio[1022]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 15:12:10 volumio-attic volumio[1022]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 15:12:10 volumio-attic volumio[1022]: info: Loading plugins from folder /data/plugins/ Apr 14 15:12:10 volumio-attic volumio[1022]: info: Loading plugin "system"... Apr 14 15:12:10 volumio-attic volumio[1022]: info: Loading plugin "appearance"... Apr 14 15:12:10 volumio-attic nmbd[788]: [2025/04/14 15:12:10.689011, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 14 15:12:10 volumio-attic nmbd[788]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Apr 14 15:12:10 volumio-attic systemd[1]: Started Samba NMB Daemon. Apr 14 15:12:10 volumio-attic systemd[1]: Starting Samba Winbind Daemon... Apr 14 15:12:10 volumio-attic winbindd[1060]: [2025/04/14 15:12:10.963496, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 14 15:12:10 volumio-attic winbindd[1060]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 14 15:12:10 volumio-attic winbindd[1060]: [2025/04/14 15:12:10.975120, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 14 15:12:10 volumio-attic systemd[1]: Started Samba Winbind Daemon. Apr 14 15:12:10 volumio-attic winbindd[1060]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 14 15:12:11 volumio-attic systemd[1]: Starting Samba SMB Daemon... Apr 14 15:12:11 volumio-attic smbd[1065]: [2025/04/14 15:12:11.369410, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 14 15:12:11 volumio-attic systemd[1]: Started Samba SMB Daemon. Apr 14 15:12:11 volumio-attic smbd[1065]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 14 15:12:11 volumio-attic systemd[1]: Reached target Multi-User System. Apr 14 15:12:11 volumio-attic systemd[1]: Reached target Graphical Interface. Apr 14 15:12:11 volumio-attic systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 14 15:12:11 volumio-attic systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 14 15:12:11 volumio-attic systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 14 15:12:11 volumio-attic systemd[1]: Startup finished in 12.459s (kernel) + 25.811s (userspace) = 38.270s. Apr 14 15:12:11 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:12:11] [connect] Successful connection Apr 14 15:12:11 volumio-attic volumio[1022]: info: Loading plugin "network"... Apr 14 15:12:11 volumio-attic volumio[1022]: info: Refreshing Cached IP Addresses Apr 14 15:12:11 volumio-attic sudo[1075]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 15:12:11 volumio-attic sudo[1075]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:11 volumio-attic sudo[1075]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:11 volumio-attic sudo[1077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 15:12:11 volumio-attic sudo[1077]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:11 volumio-attic sudo[1077]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:11 volumio-attic volumio[1022]: info: Loading plugin "services"... Apr 14 15:12:11 volumio-attic volumio[1022]: info: Loading plugin "alsa_controller"... Apr 14 15:12:11 volumio-attic sudo[1088]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 15:12:11 volumio-attic sudo[1088]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:11 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 15:12:11 volumio-attic volumio[1022]: info: Loading plugin "wizard"... Apr 14 15:12:11 volumio-attic volumio[1022]: info: Loading plugin "networkfs"... Apr 14 15:12:12 volumio-attic volumio[1022]: info: Starting Udev Watcher for removable devices Apr 14 15:12:12 volumio-attic sudo[1103]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=rainer,password=nwobhm1,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.211/common/media/mp3 /mnt/NAS/mp3 Apr 14 15:12:12 volumio-attic sudo[1103]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:12 volumio-attic volumio[1022]: info: Ignoring mount for partition: boot Apr 14 15:12:12 volumio-attic volumio[1022]: info: Ignoring mount for partition: volumio Apr 14 15:12:12 volumio-attic volumio[1022]: info: Ignoring mount for partition: volumio_data Apr 14 15:12:12 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "volumio_command_line_client"... Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "upnp"... Apr 14 15:12:12 volumio-attic volumio[1022]: info: [1744657932072] Starting Upmpd Daemon Apr 14 15:12:12 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "my_music"... Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "mpd"... Apr 14 15:12:12 volumio-attic kernel: Key type cifs.spnego registered Apr 14 15:12:12 volumio-attic kernel: Key type cifs.idmap registered Apr 14 15:12:12 volumio-attic 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 14 15:12:12 volumio-attic kernel: CIFS: Attempting to mount //192.168.1.211/common/media/mp3 Apr 14 15:12:12 volumio-attic kernel: cryptd: max_cpu_qlen set to 1000 Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "upnp_browser"... Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "alarm-clock"... Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "airplay_emulation"... Apr 14 15:12:12 volumio-attic volumio[1022]: info: Starting Shairport Sync Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "last_100"... Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "webradio"... Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "i2s_dacs"... Apr 14 15:12:12 volumio-attic volumio[1022]: info: Loading plugin "volumiodiscovery"... Apr 14 15:12:12 volumio-attic volumio[1022]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 15:12:12 volumio-attic volumio[1022]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 15:12:12 volumio-attic node[1022]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 15:12:12 volumio-attic volumio[1022]: *** WARNING *** For more information see Apr 14 15:12:12 volumio-attic volumio[1022]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 15:12:12 volumio-attic volumio[1022]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 15:12:12 volumio-attic volumio[1022]: *** WARNING *** For more information see Apr 14 15:12:12 volumio-attic node[1022]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 15:12:12 volumio-attic node[1022]: *** WARNING *** For more information see Apr 14 15:12:12 volumio-attic node[1022]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 15:12:12 volumio-attic node[1022]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 15:12:12 volumio-attic node[1022]: *** WARNING *** For more information see Apr 14 15:12:12 volumio-attic volumio[1022]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 15:12:12 volumio-attic volumio[1022]: info: Discovery: Started advertising with name: Volumio attic Apr 14 15:12:13 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 15:12:13 volumio-attic volumio[1022]: info: Loading plugin "spop"... Apr 14 15:12:13 volumio-attic sudo[1103]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:14 volumio-attic volumio[1022]: info: Loading plugin "now_playing"... Apr 14 15:12:15 volumio-attic volumio[1022]: info: Loading plugin "outputs"... Apr 14 15:12:15 volumio-attic volumio[1022]: info: Loading plugin "albumart"... Apr 14 15:12:15 volumio-attic volumio[1022]: info: Plugin example_plugin is not enabled Apr 14 15:12:15 volumio-attic volumio[1022]: info: Loading plugin "inputs"... Apr 14 15:12:15 volumio-attic volumio[1022]: info: Loading plugin "updater_comm"... Apr 14 15:12:15 volumio-attic volumio[1022]: info: Plugin mpdemulation is not enabled Apr 14 15:12:15 volumio-attic volumio[1022]: info: Loading plugin "rest_api"... Apr 14 15:12:15 volumio-attic volumio[1022]: info: Loading plugin "websocket"... Apr 14 15:12:15 volumio-attic volumio[1022]: info: Starting Socket.io Server version 2.3.0 Apr 14 15:12:15 volumio-attic volumio[1022]: info: Loading plugin "touch_display"... Apr 14 15:12:15 volumio-attic volumio[1022]: Forking 3 albumart workers Apr 14 15:12:15 volumio-attic volumio[1022]: info: Applying required configuration parameters for plugin touch_display Apr 14 15:12:15 volumio-attic volumio[1022]: info: Loading i18n strings for locale en Apr 14 15:12:15 volumio-attic volumio[1022]: Updating browse sources language Apr 14 15:12:15 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 15:12:15 volumio-attic sudo[1088]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:16 volumio-attic volumio[1022]: Starting albumart workers Apr 14 15:12:16 volumio-attic volumio[1022]: Starting albumart workers Apr 14 15:12:16 volumio-attic volumio[1022]: Starting albumart workers Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::initPlayerControls Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: Express server listening on port 3000 Apr 14 15:12:16 volumio-attic volumio[1022]: [Metrics] WebUI: 6s 817.60ms Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreStateMachine::resetVolumioState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreStateMachine::getcurrentVolume Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 15:12:16 volumio-attic volumio[1022]: info: Volumio Network Manager: Network status updated: 2 Apr 14 15:12:16 volumio-attic volumio[1022]: verbose: New Socket.io Connection to 192.168.1.65 from 192.168.1.215 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Apr 14 15:12:16 volumio-attic volumio[1022]: verbose: New Socket.io Connection to 192.168.1.65 from 192.168.1.215 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Apr 14 15:12:16 volumio-attic volumio[1022]: verbose: New Socket.io Connection to 192.168.1.65 from 192.168.1.215 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Apr 14 15:12:16 volumio-attic volumio[1022]: verbose: New Socket.io Connection to 192.168.1.65 from 192.168.1.215 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Apr 14 15:12:16 volumio-attic volumio[1022]: verbose: New Socket.io Connection to 192.168.1.65 from 192.168.1.215 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Apr 14 15:12:16 volumio-attic volumio-remote-updater[631]: [2025-04-14 15:12:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1744657931 101 Apr 14 15:12:16 volumio-attic volumio[1022]: 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: 6 Apr 14 15:12:16 volumio-attic volumio[1022]: verbose: New Socket.io Connection to 192.168.1.65:3000 from 192.168.1.217 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 14 15:12:16 volumio-attic volumio[1022]: verbose: New Socket.io Connection to 192.168.1.65:3000 from 192.168.1.217 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 14 15:12:16 volumio-attic volumio[1022]: verbose: New Socket.io Connection to 192.168.1.65 from 192.168.1.215 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Apr 14 15:12:16 volumio-attic volumio[1022]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: Reloading queue from file Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Apr 14 15:12:16 volumio-attic volumio[1022]: info: Setting Device type: Raspberry PI Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreStateMachine::setRepeat null single undefined Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreStateMachine::pushState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioPushState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreStateMachine::setRandom null Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreStateMachine::pushState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioPushState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 15:12:16 volumio-attic volumio[1022]: verbose: New Socket.io Connection to 192.168.1.65 from 192.168.1.215 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Apr 14 15:12:16 volumio-attic volumio[1022]: info: Completed loading Core Plugins Apr 14 15:12:16 volumio-attic volumio[1022]: info: Preparing to generate the ALSA configuration file Apr 14 15:12:16 volumio-attic volumio[1022]: info: VolumeController:: Volume=41 Mute =false Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreStateMachine::pushState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioPushState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreStateMachine::updateTrackBlock Apr 14 15:12:16 volumio-attic volumio[1022]: info: CorePlayQueue::getTrackBlock Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 15:12:16 volumio-attic volumio[1022]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 14 15:12:16 volumio-attic volumio[1022]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Apr 14 15:12:16 volumio-attic volumio[1022]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetVisibleSources Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 14 15:12:16 volumio-attic volumio[1022]: info: Received Get System Info Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 15:12:16 volumio-attic volumio[1022]: info: Discovery: Getting this device information Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: Listing playlists Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:16 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: Asound.conf file unchanged, so no further update is needed Apr 14 15:12:16 volumio-attic volumio[1022]: info: Output device has changed, restarting MPD Apr 14 15:12:16 volumio-attic sudo[1212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 15:12:16 volumio-attic sudo[1212]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:16 volumio-attic volumio[1022]: info: Output device has changed, restarting Shairport Sync Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 15:12:16 volumio-attic sudo[1212]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:16 volumio-attic sudo[1214]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 15:12:16 volumio-attic sudo[1214]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:16 volumio-attic systemd[1]: Stopping Music Player Daemon... Apr 14 15:12:16 volumio-attic volumio[1022]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: ___________ START PLUGINS ___________ Apr 14 15:12:16 volumio-attic volumio[1022]: info: ControllerMpd::onStart: Initializing MPD Apr 14 15:12:16 volumio-attic volumio[1022]: info: Creating MPD Configuration file Apr 14 15:12:16 volumio-attic sudo[1221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 15:12:16 volumio-attic sudo[1221]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:16 volumio-attic volumio[1022]: info: [1744657936816] CoreMusicLibrary::Adding element Media Servers Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 15:12:16 volumio-attic sudo[1221]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:16 volumio-attic sudo[1223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 15:12:16 volumio-attic sudo[1223]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 15:12:16 volumio-attic volumio[1022]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 15:12:16 volumio-attic volumio[1022]: info: [1744657936912] CoreMusicLibrary::Adding element Last_100 Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 15:12:16 volumio-attic volumio[1022]: info: [1744657936915] CoreMusicLibrary::Adding element Webradio Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 15:12:16 volumio-attic volumio[1022]: info: Initializing BBC Radios Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 15:12:16 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: Creating Spotify config file Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: [now-playing] ConfigUpdater: config is up to date. Apr 14 15:12:17 volumio-attic systemd[1]: mpd.service: Succeeded. Apr 14 15:12:17 volumio-attic volumio[1022]: info: Loading i18n strings for locale en Apr 14 15:12:17 volumio-attic systemd[1]: Stopped Music Player Daemon. Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 15:12:17 volumio-attic volumio[1022]: info: Volumio Calling Home Apr 14 15:12:17 volumio-attic systemd[1]: Starting Music Player Daemon... Apr 14 15:12:17 volumio-attic sudo[1247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Apr 14 15:12:17 volumio-attic sudo[1247]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic sudo[1249]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Apr 14 15:12:17 volumio-attic sudo[1249]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic sudo[1252]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Apr 14 15:12:17 volumio-attic sudo[1252]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic sudo[1242]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 15:12:17 volumio-attic sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic sudo[1242]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:17 volumio-attic volumio[1022]: info: [now-playing] Fetching API key... Apr 14 15:12:17 volumio-attic systemd[1]: Reloading. Apr 14 15:12:17 volumio-attic volumio[1022]: info: [now-playing] App is listening on port 4004. Apr 14 15:12:17 volumio-attic volumio[1022]: info: [now-playing] Backing up /opt/volumiokiosk.sh to /home/volumio/.now_playing/volumiokiosk.sh.bak Apr 14 15:12:17 volumio-attic sudo[1273]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i s/localhost:3000/localhost:4004/g /opt/volumiokiosk.sh Apr 14 15:12:17 volumio-attic sudo[1273]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic sudo[1273]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:17 volumio-attic volumio[1022]: [sudo] password for volumio: info: [now-playing] Executing /usr/bin/sudo /bin/systemctl status volumio-kiosk Apr 14 15:12:17 volumio-attic volumio[1022]: info: Discovery: adding 49840f1b-238f-40bd-a9d0-2e97befbc584 Apr 14 15:12:17 volumio-attic volumio[1022]: info: Discovery: Found device Volumio attic Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:17 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:17 volumio-attic sudo[1279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status volumio-kiosk Apr 14 15:12:17 volumio-attic sudo[1279]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 14 15:12:17 volumio-attic volumio[1022]: info: VolumeController:: Volume=41 Mute =false Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreStateMachine::pushState Apr 14 15:12:17 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioPushState Apr 14 15:12:17 volumio-attic volumio[1022]: info: touch_display: Backlight interface detected. Apr 14 15:12:17 volumio-attic volumio[1022]: info: Discovery: adding 91af4e5f-309c-4fe3-8277-ee3d522af188 Apr 14 15:12:17 volumio-attic volumio[1022]: info: Discovery: Found device Volumio barn Apr 14 15:12:17 volumio-attic volumio[1022]: info: Discovery: Connecting to remote: 192.168.1.217 Apr 14 15:12:17 volumio-attic volumio[1022]: info: MPD Permissions set Apr 14 15:12:17 volumio-attic volumio[1022]: info: Spotify config file written Apr 14 15:12:17 volumio-attic volumio[1022]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Apr 14 15:12:17 volumio-attic volumio[1022]: info: Volumio called home Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic sudo[1282]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 15:12:17 volumio-attic sudo[1282]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 15:12:17 volumio-attic volumio[1022]: info: No need to fix Spotify hosts Apr 14 15:12:17 volumio-attic systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Apr 14 15:12:17 volumio-attic volumio[1022]: info: Discovery: Connected to remote: 192.168.1.217 Apr 14 15:12:17 volumio-attic volumio[1022]: info: touch_display: Raspberry Pi Foundation touch screen detected. Apr 14 15:12:17 volumio-attic volumio[1022]: info: Starting Shairport Sync Apr 14 15:12:17 volumio-attic sudo[1295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Apr 14 15:12:17 volumio-attic sudo[1295]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic sudo[1293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Apr 14 15:12:17 volumio-attic sudo[1293]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic volumio[1022]: info: Starting Shairport Sync Apr 14 15:12:17 volumio-attic sudo[1295]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:17 volumio-attic volumio[1022]: info: Starting Shairport Sync Apr 14 15:12:17 volumio-attic sudo[1299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 15:12:17 volumio-attic sudo[1299]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic sudo[1293]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:17 volumio-attic sudo[1301]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 15:12:17 volumio-attic sudo[1301]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic sudo[1304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 15:12:17 volumio-attic sudo[1304]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:17 volumio-attic sudo[1249]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:17 volumio-attic systemd[1]: Reloading. Apr 14 15:12:17 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:17 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:17 volumio-attic volumio[1022]: info: touch_display: systemctl disable getty@tty1.service succeeded. Apr 14 15:12:17 volumio-attic volumio[1022]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Apr 14 15:12:17 volumio-attic volumio[1022]: info: touch_display: File permissions for backlight brightness control set. Apr 14 15:12:18 volumio-attic mpd[1256]: Apr 14 15:12 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 15:12:18 volumio-attic systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 14 15:12:18 volumio-attic systemd[1]: systemd-fsckd.service: Succeeded. Apr 14 15:12:18 volumio-attic sudo[1252]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:18 volumio-attic volumio[1022]: info: touch_display: systemctl daemon-reload succeeded. Apr 14 15:12:18 volumio-attic sudo[1322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Apr 14 15:12:18 volumio-attic sudo[1322]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:18 volumio-attic sudo[1279]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:18 volumio-attic volumio[1022]: error: [now-playing] Failed to execute systemctl command status on volumio-kiosk: Error: Command failed: /usr/bin/sudo /bin/systemctl status volumio-kiosk Apr 14 15:12:18 volumio-attic volumio[1022]: at ChildProcess.exithandler (child_process.js:308:12) Apr 14 15:12:18 volumio-attic volumio[1022]: at ChildProcess.emit (events.js:315:20) Apr 14 15:12:18 volumio-attic volumio[1022]: at maybeClose (internal/child_process.js:1048:16) Apr 14 15:12:18 volumio-attic volumio[1022]: at Process.ChildProcess._handle.onexit (internal/child_process.js:288:5) Apr 14 15:12:18 volumio-attic systemd[1]: Started Volumio Kiosk. Apr 14 15:12:18 volumio-attic systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 14 15:12:18 volumio-attic systemd[1]: Started go-librespot Daemon. Apr 14 15:12:18 volumio-attic sudo[1282]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:18 volumio-attic systemd[1]: shairport-sync.service: Succeeded. Apr 14 15:12:18 volumio-attic go-librespot[1326]: go-librespot daemon starting... Apr 14 15:12:18 volumio-attic systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 14 15:12:18 volumio-attic sudo[1247]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:18 volumio-attic sudo[1322]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:18 volumio-attic systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 14 15:12:18 volumio-attic volumio[1022]: info: touch_display: systemctl stop getty@tty1.service succeeded. Apr 14 15:12:18 volumio-attic sudo[1299]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:18 volumio-attic volumio[1022]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Apr 14 15:12:18 volumio-attic sudo[1301]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:18 volumio-attic sudo[1304]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:18 volumio-attic volumio[1022]: info: touch_display: Volumio Kiosk started. Apr 14 15:12:18 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:18 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:18 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:18 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:18 volumio-attic volumio[1022]: info: Shairport-Sync Started Apr 14 15:12:18 volumio-attic volumio[1022]: Error adding Membership: Error: addMembership EINVAL Apr 14 15:12:18 volumio-attic volumio[1022]: info: Shairport-Sync Started Apr 14 15:12:18 volumio-attic volumio[1022]: info: Shairport-Sync Started Apr 14 15:12:18 volumio-attic volumio[1022]: info: touch_display: X display number found: 0 Apr 14 15:12:18 volumio-attic volumio[1022]: info: touch_display: X display number found: 0 Apr 14 15:12:18 volumio-attic startx[1324]: X.Org X Server 1.20.4 Apr 14 15:12:18 volumio-attic startx[1324]: X Protocol Version 11, Revision 0 Apr 14 15:12:18 volumio-attic startx[1324]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Apr 14 15:12:18 volumio-attic startx[1324]: Current Operating System: Linux volumio-attic 6.6.62-v7l+ #1816 SMP Mon Nov 18 15:33:33 GMT 2024 armv7l Apr 14 15:12:18 volumio-attic startx[1324]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory numa_policy=interleave snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=E4:5F:01:AE:37:F1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=104224f7-d7af-43f8-9bc3-0adf882b37ed imgfile=/volumio_current.sqsh bootpart=UUID=815B-E7CF datapart=UUID=16ae7c3a-95a2-4b6f-8fa1-48291dd70f30 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Apr 14 15:12:18 volumio-attic startx[1324]: Build Date: 04 April 2023 07:50:56AM Apr 14 15:12:18 volumio-attic startx[1324]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Apr 14 15:12:18 volumio-attic startx[1324]: Current version of pixman: 0.36.0 Apr 14 15:12:18 volumio-attic startx[1324]: Before reporting problems, check http://wiki.x.org Apr 14 15:12:18 volumio-attic startx[1324]: to make sure that you have the latest version. Apr 14 15:12:18 volumio-attic startx[1324]: Markers: (--) probed, (**) from config file, (==) default setting, Apr 14 15:12:18 volumio-attic startx[1324]: (++) from command line, (!!) notice, (II) informational, Apr 14 15:12:18 volumio-attic startx[1324]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Apr 14 15:12:18 volumio-attic startx[1324]: (==) Log file: "/var/log/Xorg.0.log", Time: Mon Apr 14 15:12:18 2025 Apr 14 15:12:18 volumio-attic startx[1324]: (==) Using config directory: "/etc/X11/xorg.conf.d" Apr 14 15:12:18 volumio-attic startx[1324]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Apr 14 15:12:18 volumio-attic sh[561]: timed out Apr 14 15:12:18 volumio-attic dhcpcd[609]: timed out Apr 14 15:12:18 volumio-attic sh[561]: dhcpcd exited Apr 14 15:12:18 volumio-attic dhcpcd[609]: dhcpcd exited Apr 14 15:12:18 volumio-attic sh[561]: ifup: failed to bring up eth0 Apr 14 15:12:18 volumio-attic systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Apr 14 15:12:18 volumio-attic systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Apr 14 15:12:19 volumio-attic volumio[1022]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Apr 14 15:12:19 volumio-attic volumio[1022]: info: touch_display: X display number found: 0 Apr 14 15:12:19 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:19-04:00" level=info msg="running go-librespot 0.2.0" Apr 14 15:12:19 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:19-04:00" level=debug msg="app state loaded" Apr 14 15:12:19 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:19-04:00" level=debug msg="stored credentials not found" Apr 14 15:12:19 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:19-04:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 15:12:19 volumio-attic volumio[1022]: info: [now-playing] OpenWeatherMap API key obtained. Apr 14 15:12:19 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 15:12:19 volumio-attic volumio[1022]: info: Discovery: Getting this device information Apr 14 15:12:19 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:19 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:19 volumio-attic volumio[1022]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 15:12:19 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:19-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 14 15:12:19 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:19-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 14 15:12:19 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:19-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 14 15:12:19 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:19-04:00" level=info msg="zeroconf server listening on port 45141" Apr 14 15:12:20 volumio-attic volumio[1022]: info: touch_display: Setting screensaver timeout to 0 seconds. Apr 14 15:12:20 volumio-attic systemd[1]: systemd-hostnamed.service: Succeeded. Apr 14 15:12:20 volumio-attic systemd[1]: Started Music Player Daemon. Apr 14 15:12:20 volumio-attic sudo[1214]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:20 volumio-attic sudo[1223]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:20 volumio-attic volumio[1022]: info: Completed starting Core Plugins Apr 14 15:12:20 volumio-attic volumio[1022]: info: ------------------------------------------- Apr 14 15:12:20 volumio-attic volumio[1022]: info: ----- MyVolumio plugins startup ---- Apr 14 15:12:20 volumio-attic volumio[1022]: info: ------------------------------------------- Apr 14 15:12:20 volumio-attic volumio[1022]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 15:12:20 volumio-attic volumio[1022]: error: MPD error: The expression evaluated to a falsy value: Apr 14 15:12:20 volumio-attic volumio[1022]: assert.ok(self.idling) Apr 14 15:12:20 volumio-attic volumio[1022]: error: The expression evaluated to a falsy value: Apr 14 15:12:20 volumio-attic volumio[1022]: assert.ok(self.idling) Apr 14 15:12:20 volumio-attic volumio[1022]: info: MPD running with PID1256 Apr 14 15:12:20 volumio-attic volumio[1022]: ,establishing connection Apr 14 15:12:20 volumio-attic volumio[1022]: error: updateQueue error: null Apr 14 15:12:20 volumio-attic volumio[1022]: error: updateQueue error: null Apr 14 15:12:21 volumio-attic volumio[1022]: info: go-librespot daemon successfully initialized Apr 14 15:12:22 volumio-attic sudo[1472]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 15:12:22 volumio-attic sudo[1472]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:22 volumio-attic sudo[1472]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:22 volumio-attic sudo[1474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 15:12:22 volumio-attic sudo[1474]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:22 volumio-attic sudo[1474]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:22 volumio-attic sudo[1478]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 15:12:22 volumio-attic sudo[1478]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 14 15:12:22 volumio-attic systemd[1]: Started UPnP Renderer front-end to MPD. Apr 14 15:12:22 volumio-attic sudo[1478]: pam_unix(sudo:session): session closed for user root Apr 14 15:12:22 volumio-attic volumio[1022]: info: Upmpdcli Daemon Started Apr 14 15:12:22 volumio-attic volumio[1480]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 14 15:12:23 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:23-04:00" level=debug msg="obtained new client token: AABcT7MVNmFWaKd8CMOuRvnbCsuxJV3oLLIGwXqCKztC3V/BqmLGq5UP2X3ECWZfW72ELUGJzj9JO/L0BheuqybxNK4eSVEBMqI9WYvQ4wJSbi8qtjKKKFmqSg6c2NnVv9xcp0P9ymx3QZW9EYuE+0TYllJ6Zb/fzvT3yOof4UoYrFtXN7DMwnxEGi3t/IXJRALxv0peHm/wyMF2etPDVhUP1+GIIoOpxGrSe/USiDAafO5FA5Di080=" Apr 14 15:12:23 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:23-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 14 15:12:23 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:23-04:00" level=debug msg="completed keyexchange" Apr 14 15:12:23 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:23-04:00" level=debug msg="completed challenge" Apr 14 15:12:23 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:23-04:00" level=info msg="authenticated AP as 31t44d5scnxm2w5rngt2s4oovf5e" Apr 14 15:12:23 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:23-04:00" level=info msg="authenticated Login5 as 31t44d5scnxm2w5rngt2s4oovf5e" Apr 14 15:12:23 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:23-04:00" level=info msg="accepted zeroconf user 31t44d5scnxm2w5rngt2s4oovf5e from RAINER2022" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="dealer connection opened" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=trace msg="starting accesspoint recv loop" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=trace msg="starting dealer recv loop" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=trace msg="received accesspoint ping" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="received connection id: NWMzZDk2NzEtMmJjNC00MjM1LTllMTItMzZiYTY0ZTBkMDhmK2RlYWxlcit0Y3A6Ly8wYWNiZjkzZC5pcC5ndWUxLnNwb3RpZnkubmV0OjU3MDArQUY0Q0Y4QkQ3ODAxRjA5REZGQTlGMzY3RTg2OUZCQkQxODVDRjFFNENDRTQzRjQyRjQyQjY0QzhCOTA0ODc4OQ==" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=trace msg="received accesspoint pong ack" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="put connect state because NEW_DEVICE" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="handling transfer player command from 37c1c00b3816d639f139fef8f25af8585f491301" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="resolved context of track" uri="spotify:album:4XXpD9AVoTbPkuv41jk2Zm" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:album:4XXpD9AVoTbPkuv41jk2Zm" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="loading track (paused: false, position: 52714ms)" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=trace msg="emitting websocket event: will_play" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="selected format OGG_VORBIS_320 (2fc6ac9142dfa7600705ec2bcdd302b1249e78ac)" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="requested aes key for file 2fc6ac9142dfa7600705ec2bcdd302b1249e78ac, gid: 4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1392" Apr 14 15:12:24 volumio-attic volumio[1022]: info: Initializing connection to go-librespot Websocket Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="new websocket client" Apr 14 15:12:24 volumio-attic volumio[1022]: info: Connection to go-librespot Websocket established Apr 14 15:12:24 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:24-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1143" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="fetched first chunk of 17, total size is 8857089 bytes" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="fetched chunk 5/16, size: 524288" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="fetched chunk 4/16, size: 524288" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=trace msg="seek to 52714ms (diff: 47ms, samples: 2324687, bytes: 2189232)" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="created new output device" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="fetched chunk 6/16, size: 524288" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=info msg="loaded track \"Creature From the Deep\" (paused: false, position: 52714ms, duration: 219850ms, prefetched: false)" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="fetched chunk 7/16, size: 524288" uri="spotify:track:4lDViA3AJa26d56fkGZcyh" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=trace msg="scheduling prefetch in 137s" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=trace msg="emitting websocket event: metadata" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=trace msg="emitting websocket event: active" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="sending successful reply for dealer request" Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 14 15:12:25 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:25-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 14 15:12:26 volumio-attic volumio[1022]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4lDViA3AJa26d56fkGZcyh","name":"Creature From the Deep","artist_names":["Leper Colony"],"album_name":"Creature From the Deep","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02672903a5cdeae0867bf162c1","position":52714,"duration":219850,"release_date":"year:2025 month:3 day:5","track_number":1,"disc_number":1}} Apr 14 15:12:26 volumio-attic volumio[1022]: SPOTIFY: received: {"type":"active","data":null} Apr 14 15:12:26 volumio-attic volumio[1022]: info: Aligning Spotify Volume to Volumio Volume Apr 14 15:12:26 volumio-attic volumio[1022]: info: CoreCommandRouter::volumioGetState Apr 14 15:12:26 volumio-attic volumio[1022]: info: CorePlayQueue::getTrack 0 Apr 14 15:12:26 volumio-attic volumio[1022]: info: Setting Spotify Volume from Volumio: 41 Apr 14 15:12:26 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:26-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 14 15:12:26 volumio-attic go-librespot[1326]: time="2025-04-14T15:12:26-04:00" level=trace msg="emitting websocket event: playing" Apr 14 15:12:26 volumio-attic volumio[1022]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4lDViA3AJa26d56fkGZcyh","play_origin":"album"}} Apr 14 15:12:26 volumio-attic volumio[1022]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 15:12:26 volumio-attic volumio[1022]: TypeError: Cannot read property 'service' of undefined Apr 14 15:12:26 volumio-attic volumio[1022]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:340:50) Apr 14 15:12:26 volumio-attic volumio[1022]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:266:18) Apr 14 15:12:26 volumio-attic volumio[1022]: at WebSocket.message (/data/plugins/music_service/spop/index.js:193:14) Apr 14 15:12:26 volumio-attic volumio[1022]: at WebSocket.emit (events.js:315:20) Apr 14 15:12:26 volumio-attic volumio[1022]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Apr 14 15:12:26 volumio-attic volumio[1022]: at Receiver.emit (events.js:315:20) Apr 14 15:12:26 volumio-attic volumio[1022]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Apr 14 15:12:26 volumio-attic volumio[1022]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Apr 14 15:12:26 volumio-attic volumio[1022]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Apr 14 15:12:26 volumio-attic volumio[1022]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Apr 14 15:12:26 volumio-attic volumio[1022]: at writeOrBuffer (internal/streams/writable.js:358:12) Apr 14 15:12:26 volumio-attic volumio[1022]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Apr 14 15:12:26 volumio-attic volumio[1022]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Apr 14 15:12:26 volumio-attic volumio[1022]: at Socket.emit (events.js:315:20) Apr 14 15:12:26 volumio-attic volumio[1022]: at addChunk (internal/streams/readable.js:309:12) Apr 14 15:12:26 volumio-attic volumio[1022]: at readableAddChunk (internal/streams/readable.js:284:9) Apr 14 15:12:26 volumio-attic volumio[1022]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 15:12:26 volumio-attic sudo[1612]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-14 15:11 Apr 14 15:12:26 volumio-attic sudo[1612]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"