-- Logs begin at Thu 2019-02-14 10:11:59 GMT, end at Sat 2024-10-26 02:28:11 BST. -- Oct 26 02:27:47 x2 fake-hwclock[333]: Sat Oct 26 01:27:47 UTC 2024 Oct 26 02:27:47 x2 systemd[1]: Starting Load/Save Random Seed... Oct 26 02:27:47 x2 systemd[1]: Starting Create System Users... Oct 26 02:27:47 x2 systemd[1]: dynamicswap.service: Succeeded. Oct 26 02:27:47 x2 systemd[1]: Started Load Kernel Modules. Oct 26 02:27:47 x2 systemd[1]: Started Restore / save the current clock. Oct 26 02:27:47 x2 systemd[1]: Starting Apply Kernel Variables... Oct 26 02:27:47 x2 systemd[1]: Mounting Kernel Configuration File System... Oct 26 02:27:47 x2 systemd[1]: Mounting FUSE Control File System... Oct 26 02:27:47 x2 systemd[1]: Mounted Kernel Configuration File System. Oct 26 02:27:47 x2 systemd[1]: Mounted FUSE Control File System. Oct 26 02:27:47 x2 systemd[1]: Started Load/Save Random Seed. Oct 26 02:27:47 x2 systemd[1]: Started Apply Kernel Variables. Oct 26 02:27:47 x2 systemd[1]: Started Create System Users. Oct 26 02:27:47 x2 systemd[1]: Starting Create Static Device Nodes in /dev... Oct 26 02:27:47 x2 systemd[1]: Started udev Coldplug all Devices. Oct 26 02:27:47 x2 systemd[1]: Starting Helper to synchronize boot up for ifupdown... Oct 26 02:27:47 x2 systemd[1]: Started Create Static Device Nodes in /dev. Oct 26 02:27:47 x2 systemd[1]: Reached target Local File Systems (Pre). Oct 26 02:27:47 x2 systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Oct 26 02:27:47 x2 systemd[1]: Mounting /tmp... Oct 26 02:27:47 x2 systemd[1]: Mounting /var/spool/cups... Oct 26 02:27:47 x2 systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Oct 26 02:27:47 x2 systemd[1]: Mounting /var/log... Oct 26 02:27:47 x2 systemd[1]: Starting udev Kernel Device Manager... Oct 26 02:27:47 x2 systemd[1]: Started Helper to synchronize boot up for ifupdown. Oct 26 02:27:47 x2 systemd[1]: Mounted /tmp. Oct 26 02:27:47 x2 systemd[1]: Mounted /var/spool/cups. Oct 26 02:27:47 x2 systemd[1]: Mounted /var/log. Oct 26 02:27:47 x2 systemd[1]: Starting Flush Journal to Persistent Storage... Oct 26 02:27:47 x2 systemd[1]: Mounting /var/spool/cups/tmp... Oct 26 02:27:47 x2 systemd[1]: Mounted /var/spool/cups/tmp. Oct 26 02:27:47 x2 systemd-udevd[374]: Network interface NamePolicy= disabled on kernel command line, ignoring. Oct 26 02:27:47 x2 systemd-journald[325]: Runtime journal (/run/log/journal/d9a3e155a633914cdbe1662066e99934) is 7.5M, max 30.0M, 22.5M free. Oct 26 02:27:47 x2 systemd[1]: Started Flush Journal to Persistent Storage. Oct 26 02:27:47 x2 systemd[1]: Started udev Kernel Device Manager. Oct 26 02:27:47 x2 systemd[1]: Starting Show Plymouth Boot Screen... Oct 26 02:27:47 x2 systemd[1]: plymouth-start.service: Succeeded. Oct 26 02:27:47 x2 systemd[1]: Started Show Plymouth Boot Screen. Oct 26 02:27:47 x2 systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Oct 26 02:27:47 x2 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Oct 26 02:27:47 x2 systemd[1]: Reached target Paths. Oct 26 02:27:47 x2 systemd[1]: Reached target Local Encrypted Volumes. Oct 26 02:27:48 x2 kernel: rpi-gpiomem fe200000.gpiomem: window base 0xfe200000 size 0x00001000 Oct 26 02:27:48 x2 kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Oct 26 02:27:48 x2 kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Oct 26 02:27:48 x2 kernel: [vc_sm_connected_init]: start Oct 26 02:27:48 x2 systemd-udevd[403]: Using default interface naming scheme 'v240'. Oct 26 02:27:48 x2 kernel: [vc_sm_connected_init]: installed successfully Oct 26 02:27:48 x2 kernel: rpi-gpiomem fe200000.gpiomem: initialised 1 regions as /dev/gpiomem Oct 26 02:27:48 x2 kernel: mc: Linux media interface: v0.10 Oct 26 02:27:48 x2 systemd-udevd[403]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Oct 26 02:27:48 x2 kernel: input: raspberrypi-ts as /devices/platform/soc/soc:firmware/soc:firmware:touchscreen/input/input0 Oct 26 02:27:48 x2 kernel: videodev: Linux video capture interface: v2.00 Oct 26 02:27:48 x2 kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Oct 26 02:27:48 x2 kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Oct 26 02:27:48 x2 kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Oct 26 02:27:48 x2 kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Oct 26 02:27:49 x2 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Oct 26 02:27:49 x2 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Oct 26 02:27:49 x2 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Oct 26 02:27:49 x2 kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Oct 26 02:27:49 x2 kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned. Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Oct 26 02:27:49 x2 systemd-udevd[405]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Oct 26 02:27:49 x2 kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Oct 26 02:27:49 x2 kernel: rpivid feb10000.codec: Device registered as /dev/video19 Oct 26 02:27:49 x2 kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Oct 26 02:27:49 x2 kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Oct 26 02:27:49 x2 kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Oct 26 02:27:49 x2 kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Oct 26 02:27:49 x2 kernel: bcm2835_audio bcm2835_audio: card created with 8 channels Oct 26 02:27:49 x2 kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Oct 26 02:27:49 x2 kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Oct 26 02:27:49 x2 kernel: usbcore: registered new interface driver brcmfmac Oct 26 02:27:49 x2 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Oct 26 02:27:49 x2 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Oct 26 02:27:49 x2 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Oct 26 02:27:49 x2 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Oct 26 02:27:49 x2 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Oct 26 02:27:49 x2 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Oct 26 02:27:49 x2 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Oct 26 02:27:49 x2 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Oct 26 02:27:49 x2 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Oct 26 02:27:49 x2 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Oct 26 02:27:49 x2 systemd[1]: Found device /dev/disk/by-uuid/9C48-E5A3. Oct 26 02:27:49 x2 kernel: Bluetooth: Core ver 2.22 Oct 26 02:27:49 x2 kernel: NET: Registered PF_BLUETOOTH protocol family Oct 26 02:27:49 x2 kernel: Bluetooth: HCI device and connection manager initialized Oct 26 02:27:49 x2 kernel: Bluetooth: HCI socket layer initialized Oct 26 02:27:49 x2 kernel: Bluetooth: L2CAP socket layer initialized Oct 26 02:27:49 x2 kernel: Bluetooth: SCO socket layer initialized Oct 26 02:27:49 x2 kernel: Bluetooth: HCI UART driver ver 2.3 Oct 26 02:27:49 x2 kernel: Bluetooth: HCI UART protocol H4 registered Oct 26 02:27:49 x2 kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Oct 26 02:27:49 x2 kernel: Bluetooth: HCI UART protocol Broadcom registered Oct 26 02:27:49 x2 kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Oct 26 02:27:49 x2 kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Oct 26 02:27:49 x2 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 Oct 26 02:27:49 x2 kernel: uart-pl011 fe201000.serial: no DMA platform data Oct 26 02:27:49 x2 systemd-udevd[377]: Using default interface naming scheme 'v240'. Oct 26 02:27:49 x2 systemd-udevd[377]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Oct 26 02:27:50 x2 kernel: Bluetooth: hci0: BCM: chip id 107 Oct 26 02:27:50 x2 kernel: Bluetooth: hci0: BCM: features 0x2f Oct 26 02:27:50 x2 kernel: Bluetooth: hci0: BCM4345C0 Oct 26 02:27:50 x2 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Oct 26 02:27:50 x2 kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Oct 26 02:27:50 x2 systemd-udevd[380]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 26 02:27:50 x2 kernel: snd-rpi-iqaudio-dac soc:sound: snd_rpi_iqaudio_gpio_unmute: un-muting amp using GPIO22 Oct 26 02:27:50 x2 systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Oct 26 02:27:50 x2 systemd-udevd[395]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 26 02:27:50 x2 systemd[1]: Created slice system-bthelper.slice. Oct 26 02:27:50 x2 systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Oct 26 02:27:50 x2 systemd[1]: Starting Show Plymouth Boot Screen... Oct 26 02:27:50 x2 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Oct 26 02:27:50 x2 systemd[1]: Condition check resulted in Huge Pages File System being skipped. Oct 26 02:27:50 x2 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Oct 26 02:27:50 x2 systemd[1]: Created slice system-systemd\x2dbacklight.slice. Oct 26 02:27:50 x2 systemd[1]: Starting Load/Save Screen Backlight Brightness of backlight:rpi_backlight... Oct 26 02:27:50 x2 systemd[1]: Starting File System Check on /dev/disk/by-uuid/9C48-E5A3... Oct 26 02:27:50 x2 systemd[1]: Started Load/Save Screen Backlight Brightness of backlight:rpi_backlight. Oct 26 02:27:50 x2 systemd[1]: plymouth-start.service: Succeeded. Oct 26 02:27:50 x2 systemd[1]: Started Show Plymouth Boot Screen. Oct 26 02:27:50 x2 systemd[1]: Started File System Check Daemon to report status. Oct 26 02:27:50 x2 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Oct 26 02:27:50 x2 systemd[1]: Starting Load/Save RF Kill Switch Status... Oct 26 02:27:50 x2 systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Oct 26 02:27:50 x2 systemd[1]: Started Load/Save RF Kill Switch Status. Oct 26 02:27:50 x2 kernel: Bluetooth: hci0: BCM: features 0x2f Oct 26 02:27:50 x2 kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Oct 26 02:27:50 x2 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Oct 26 02:27:50 x2 systemd-fsck[554]: fsck.fat 4.1 (2017-01-24) Oct 26 02:27:50 x2 systemd-fsck[554]: /dev/mmcblk0p1: 370 files, 134161/184582 clusters Oct 26 02:27:50 x2 systemd[1]: Started File System Check on /dev/disk/by-uuid/9C48-E5A3. Oct 26 02:27:50 x2 systemd[1]: Mounting /boot... Oct 26 02:27:50 x2 systemd[1]: Mounted /boot. Oct 26 02:27:50 x2 systemd[1]: Reached target Local File Systems. Oct 26 02:27:50 x2 systemd[1]: Started ifup for eth0. Oct 26 02:27:50 x2 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Oct 26 02:27:50 x2 systemd[1]: Started ifup for wlan0. Oct 26 02:27:50 x2 systemd[1]: Starting Raise network interfaces... Oct 26 02:27:50 x2 systemd[1]: Starting Preprocess NFS configuration... Oct 26 02:27:50 x2 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Oct 26 02:27:50 x2 systemd[1]: Starting Create Volatile Files and Directories... Oct 26 02:27:50 x2 systemd[1]: plymouth-read-write.service: Succeeded. Oct 26 02:27:51 x2 systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Oct 26 02:27:51 x2 systemd[1]: Received SIGRTMIN+20 from PID 221 (plymouthd). Oct 26 02:27:51 x2 systemd[1]: nfs-config.service: Succeeded. Oct 26 02:27:51 x2 systemd[1]: Started Preprocess NFS configuration. Oct 26 02:27:51 x2 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Oct 26 02:27:51 x2 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Oct 26 02:27:51 x2 systemd[1]: Reached target NFS client services. Oct 26 02:27:51 x2 systemd[1]: Started Create Volatile Files and Directories. Oct 26 02:27:51 x2 systemd[1]: Starting Update UTMP about System Boot/Shutdown... Oct 26 02:27:51 x2 systemd[1]: Starting RPC bind portmap service... Oct 26 02:27:51 x2 systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Oct 26 02:27:51 x2 systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Oct 26 02:27:51 x2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 26 02:27:51 x2 systemd[1]: Started Update UTMP about System Boot/Shutdown. Oct 26 02:27:51 x2 systemd[1]: Reached target System Initialization. Oct 26 02:27:51 x2 systemd[1]: Started Daily Cleanup of Temporary Directories. Oct 26 02:27:51 x2 kernel: 8021q: 802.1Q VLAN Support v1.8 Oct 26 02:27:51 x2 systemd[1]: Listening on D-Bus System Message Bus Socket. Oct 26 02:27:51 x2 systemd[1]: Started Daily man-db regeneration. Oct 26 02:27:51 x2 systemd[1]: Started Daily apt download activities. Oct 26 02:27:51 x2 systemd[1]: Listening on triggerhappy.socket. Oct 26 02:27:51 x2 systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Oct 26 02:27:51 x2 systemd[1]: Reached target Sockets. Oct 26 02:27:51 x2 systemd[1]: Started Daily apt upgrade and clean activities. Oct 26 02:27:51 x2 systemd[1]: Reached target Timers. Oct 26 02:27:51 x2 systemd[1]: Reached target Basic System. Oct 26 02:27:51 x2 systemd[1]: Started D-Bus System Message Bus. Oct 26 02:27:51 x2 systemd[1]: Started Volumio Log Rotation Service. Oct 26 02:27:51 x2 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Oct 26 02:27:51 x2 systemd[1]: Reached target Login Prompts. Oct 26 02:27:51 x2 systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Oct 26 02:27:51 x2 systemd[1]: Starting triggerhappy global hotkey daemon... Oct 26 02:27:51 x2 systemd[1]: Starting dhcpcd on all interfaces... Oct 26 02:27:51 x2 systemd[1]: Started UPnP Renderer front-end to MPD. Oct 26 02:27:51 x2 thd[670]: Unable to parse trigger line: Oct 26 02:27:51 x2 thd[670]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Oct 26 02:27:51 x2 thd[670]: Unable to parse trigger line: Oct 26 02:27:51 x2 thd[670]: Found socket passed from systemd Oct 26 02:27:51 x2 dhcpcd[672]: Not running dhcpcd because /etc/network/interfaces Oct 26 02:27:51 x2 dhcpcd[672]: defines some interfaces that will use a Oct 26 02:27:51 x2 dhcpcd[672]: DHCP client or static address Oct 26 02:27:51 x2 systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Oct 26 02:27:51 x2 systemd[1]: Starting Configure Bluetooth Modems connected by UART... Oct 26 02:27:51 x2 systemd[1]: Starting Wireless Services... Oct 26 02:27:51 x2 systemd[1]: Starting WPA supplicant... Oct 26 02:27:51 x2 systemd[1]: Starting Login Service... Oct 26 02:27:51 x2 systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Oct 26 02:27:51 x2 systemd[1]: Started volumio-remote-updater.service. Oct 26 02:27:51 x2 sh[565]: eth0: waiting for carrier Oct 26 02:27:51 x2 kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Oct 26 02:27:51 x2 kernel: bcmgenet fd580000.ethernet eth0: Link is Down Oct 26 02:27:51 x2 dhcpcd[614]: eth0: waiting for carrier Oct 26 02:27:51 x2 systemd[1]: Started Volumio Iptables Module. Oct 26 02:27:51 x2 systemd[1]: Started Manage Sound Card State (restore and store). Oct 26 02:27:51 x2 systemd[1]: Starting Save/Restore Sound Card State... Oct 26 02:27:51 x2 systemd[1]: Started RPC bind portmap service. Oct 26 02:27:51 x2 systemd[1]: Started triggerhappy global hotkey daemon. Oct 26 02:27:51 x2 alsactl[692]: alsactl 1.1.8 daemon started Oct 26 02:27:51 x2 systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Oct 26 02:27:51 x2 systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Oct 26 02:27:51 x2 systemd[1]: Failed to start dhcpcd on all interfaces. Oct 26 02:27:51 x2 systemd[1]: hciuart.service: Succeeded. Oct 26 02:27:51 x2 systemd[1]: Started Configure Bluetooth Modems connected by UART. Oct 26 02:27:51 x2 systemd[1]: Started Save/Restore Sound Card State. Oct 26 02:27:51 x2 systemd[1]: Reached target Sound Card. Oct 26 02:27:51 x2 avahi-daemon[678]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Oct 26 02:27:51 x2 avahi-daemon[678]: Successfully dropped root privileges. Oct 26 02:27:52 x2 systemd-logind[687]: New seat seat0. Oct 26 02:27:51 x2 avahi-daemon[678]: avahi-daemon 0.7 starting up. Oct 26 02:27:52 x2 systemd[1]: Starting Raspberry Pi bluetooth helper... Oct 26 02:27:52 x2 systemd[1]: Reached target Remote File Systems (Pre). Oct 26 02:27:52 x2 systemd[1]: Reached target Remote File Systems. Oct 26 02:27:52 x2 systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Oct 26 02:27:52 x2 systemd[1]: Reached target RPC Port Mapper. Oct 26 02:27:52 x2 sh[568]: wlan0=wlan0 Oct 26 02:27:52 x2 bthelper[705]: Raspberry Pi BDADDR already set Oct 26 02:27:52 x2 systemd[1]: Started Raspberry Pi bluetooth helper. Oct 26 02:27:52 x2 avahi-daemon[678]: Successfully called chroot(). Oct 26 02:27:52 x2 avahi-daemon[678]: Successfully dropped remaining capabilities. Oct 26 02:27:52 x2 wpa_supplicant[685]: Successfully initialized wpa_supplicant Oct 26 02:27:52 x2 avahi-daemon[678]: Loading service file /services/volumio.service. Oct 26 02:27:52 x2 avahi-daemon[678]: Network interface enumeration completed. Oct 26 02:27:52 x2 avahi-daemon[678]: Server startup complete. Host name is x2.local. Local service cookie is 1334576469. Oct 26 02:27:52 x2 avahi-daemon[678]: Service "x2" (/services/volumio.service) successfully established. Oct 26 02:27:52 x2 systemd[1]: Started Raise network interfaces. Oct 26 02:27:52 x2 systemd[1]: Started Login Service. Oct 26 02:27:52 x2 systemd[1]: Started Avahi mDNS/DNS-SD Stack. Oct 26 02:27:52 x2 systemd[1]: Started WPA supplicant. Oct 26 02:27:52 x2 systemd[1]: Reached target Network. Oct 26 02:27:52 x2 systemd[1]: Starting Permit User Sessions... Oct 26 02:27:52 x2 systemd[1]: Starting Network Time Service... Oct 26 02:27:52 x2 systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Oct 26 02:27:52 x2 systemd[1]: Starting OpenBSD Secure Shell server... Oct 26 02:27:52 x2 systemd[1]: Reached target Network is Online. Oct 26 02:27:53 x2 systemd[1]: Starting /etc/rc.local Compatibility... Oct 26 02:27:53 x2 systemd[1]: Starting LSB: Brings up/down network automatically... Oct 26 02:27:53 x2 systemd[1]: Starting Samba NMB Daemon... Oct 26 02:27:53 x2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 26 02:27:53 x2 volumio-remote-updater[688]: Error: No active session Oct 26 02:27:53 x2 systemd[1]: Starting Bluetooth service... Oct 26 02:27:53 x2 volumio-remote-updater[688]: [2024-10-26 02:27:53] [info] asio async_connect error: system:111 (Connection refused) Oct 26 02:27:53 x2 volumio-remote-updater[688]: [2024-10-26 02:27:53] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 26 02:27:53 x2 volumio-remote-updater[688]: [2024-10-26 02:27:53] [error] handle_connect error: Underlying Transport Error Oct 26 02:27:53 x2 systemd[1]: Started Permit User Sessions. Oct 26 02:27:53 x2 systemd[1]: Started /etc/rc.local Compatibility. Oct 26 02:27:53 x2 systemd[1]: Starting Terminate Plymouth Boot Screen... Oct 26 02:27:53 x2 volumio[677]: Could not open config: /tmp/upmpdcli.conf Oct 26 02:27:53 x2 systemd[1]: Starting Hold until boot process finishes up... Oct 26 02:27:53 x2 ntpd[754]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 26 02:27:53 x2 ntpd[754]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Oct 26 02:27:53 x2 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Oct 26 02:27:53 x2 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Oct 26 02:27:53 x2 systemd[1]: Started Network Time Service. Oct 26 02:27:53 x2 systemd[1]: iptables.service: Succeeded. Oct 26 02:27:53 x2 systemd[1]: Received SIGRTMIN+21 from PID 221 (plymouthd). Oct 26 02:27:53 x2 loadcpufreq[711]: Loading cpufreq kernel modules...done (none). Oct 26 02:27:53 x2 ntpd[801]: proto: precision = 2.018 usec (-19) Oct 26 02:27:53 x2 systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Oct 26 02:27:53 x2 systemd[1]: plymouth-quit.service: Succeeded. Oct 26 02:27:53 x2 systemd[1]: Started Terminate Plymouth Boot Screen. Oct 26 02:27:53 x2 systemd[1]: plymouth-quit-wait.service: Succeeded. Oct 26 02:27:53 x2 systemd[1]: Started Hold until boot process finishes up. Oct 26 02:27:53 x2 systemd[1]: Received SIGRTMIN+21 from PID 221 (plymouthd). Oct 26 02:27:53 x2 ntpd[801]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 26 02:27:53 x2 ntpd[801]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 26 02:27:53 x2 ntpd[801]: Listen and drop on 0 v6wildcard [::]:123 Oct 26 02:27:53 x2 ntpd[801]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 26 02:27:53 x2 ntpd[801]: Listen normally on 2 lo 127.0.0.1:123 Oct 26 02:27:53 x2 ntpd[801]: Listening on routing socket on fd #19 for interface updates Oct 26 02:27:53 x2 ntpd[801]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 26 02:27:53 x2 ntpd[801]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 26 02:27:53 x2 ifplugd(eth0)[813]: ifplugd 0.28 initializing. Oct 26 02:27:53 x2 ifplugd(eth0)[813]: Using interface eth0/DC:A6:32:AC:46:7D with driver (version: 6.1.69-v7l+) Oct 26 02:27:53 x2 ifplugd(eth0)[813]: Using detection mode: SIOCETHTOOL Oct 26 02:27:53 x2 systemd[1]: Starting LSB: set CPUFreq kernel parameters... Oct 26 02:27:53 x2 ifplugd(eth0)[813]: Initialization complete, link beat not detected. Oct 26 02:27:53 x2 ifplugd[768]: Network Interface Plugging Daemon...start eth0...done. Oct 26 02:27:53 x2 systemd[1]: Started LSB: Brings up/down network automatically. Oct 26 02:27:53 x2 sshd[818]: Server listening on 0.0.0.0 port 22. Oct 26 02:27:53 x2 sshd[818]: Server listening on :: port 22. Oct 26 02:27:53 x2 systemd[1]: Started OpenBSD Secure Shell server. Oct 26 02:27:53 x2 bluetoothd[779]: Bluetooth daemon 5.50 Oct 26 02:27:53 x2 bluetoothd[779]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Oct 26 02:27:53 x2 systemd[1]: Started Bluetooth service. Oct 26 02:27:53 x2 systemd[1]: Reached target Bluetooth. Oct 26 02:27:53 x2 cpufrequtils[805]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Oct 26 02:27:53 x2 systemd[1]: Started LSB: set CPUFreq kernel parameters. Oct 26 02:27:53 x2 bluetoothd[779]: Starting SDP server Oct 26 02:27:53 x2 bluetoothd[779]: Excluding (cli) sap Oct 26 02:27:53 x2 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Oct 26 02:27:53 x2 kernel: Bluetooth: BNEP filters: protocol multicast Oct 26 02:27:53 x2 kernel: Bluetooth: BNEP socket layer initialized Oct 26 02:27:53 x2 bluetoothd[779]: Bluetooth management interface 1.22 initialized Oct 26 02:27:53 x2 dbus-daemon[651]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=779 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Oct 26 02:27:53 x2 kernel: Bluetooth: MGMT ver 1.22 Oct 26 02:27:54 x2 bluetoothd[779]: Failed to set privacy: Rejected (0x0b) Oct 26 02:27:54 x2 systemd[1]: Starting Hostname Service... Oct 26 02:27:54 x2 dbus-daemon[651]: [system] Successfully activated service 'org.freedesktop.hostname1' Oct 26 02:27:54 x2 systemd[1]: Started Hostname Service. Oct 26 02:27:54 x2 haveged[636]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Oct 26 02:27:54 x2 haveged[636]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Oct 26 02:27:54 x2 haveged[636]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00059 Oct 26 02:27:54 x2 haveged[636]: haveged: fills: 0, generated: 0 Oct 26 02:27:54 x2 nmbd[787]: [2024/10/26 02:27:54.447332, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Oct 26 02:27:54 x2 nmbd[787]: started asyncdns process 837 Oct 26 02:27:54 x2 nmbd[787]: [2024/10/26 02:27:54.450052, 0] ../lib/util/become_daemon.c:149(daemon_status) Oct 26 02:27:54 x2 nmbd[787]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Oct 26 02:27:54 x2 nmbd[787]: [2024/10/26 02:27:54.450618, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Oct 26 02:27:54 x2 nmbd[787]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Oct 26 02:27:54 x2 ntpd[801]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Oct 26 02:27:54 x2 wireless.js[684]: Cleaning previous... Oct 26 02:27:54 x2 sudo[845]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 26 02:27:54 x2 sudo[845]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:27:54 x2 sudo[845]: pam_unix(sudo:session): session closed for user root Oct 26 02:27:54 x2 sudo[847]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 26 02:27:54 x2 sudo[847]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:27:55 x2 sudo[847]: pam_unix(sudo:session): session closed for user root Oct 26 02:27:55 x2 wireless.js[684]: Stopped aP Oct 26 02:27:55 x2 ntpd[801]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Oct 26 02:27:55 x2 sudo[854]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 26 02:27:55 x2 sudo[854]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:27:55 x2 sudo[854]: pam_unix(sudo:session): session closed for user root Oct 26 02:27:55 x2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 26 02:27:55 x2 sudo[856]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Oct 26 02:27:55 x2 sudo[856]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:27:55 x2 sudo[856]: pam_unix(sudo:session): session closed for user root Oct 26 02:27:55 x2 sudo[863]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 26 02:27:55 x2 sudo[863]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:27:55 x2 sudo[863]: pam_unix(sudo:session): session closed for user root Oct 26 02:27:55 x2 sudo[865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Oct 26 02:27:55 x2 sudo[865]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:27:55 x2 systemd[1]: systemd-rfkill.service: Succeeded. Oct 26 02:27:55 x2 sh[565]: eth0: carrier acquired Oct 26 02:27:55 x2 dhcpcd[614]: eth0: carrier acquired Oct 26 02:27:55 x2 kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Oct 26 02:27:55 x2 sh[565]: DUID 00:01:00:01:2e:7c:57:98:dc:a6:32:ac:46:7d Oct 26 02:27:55 x2 sh[565]: eth0: IAID 32:ac:46:7d Oct 26 02:27:55 x2 dhcpcd[614]: DUID 00:01:00:01:2e:7c:57:98:dc:a6:32:ac:46:7d Oct 26 02:27:55 x2 dhcpcd[614]: eth0: IAID 32:ac:46:7d Oct 26 02:27:55 x2 sh[565]: eth0: adding address fe80::994f:e4e7:dec3:5203 Oct 26 02:27:55 x2 sh[565]: ipv6_addaddr1: Permission denied Oct 26 02:27:55 x2 dhcpcd[614]: eth0: adding address fe80::994f:e4e7:dec3:5203 Oct 26 02:27:55 x2 dhcpcd[614]: ipv6_addaddr1: Permission denied Oct 26 02:27:55 x2 sh[565]: eth0: soliciting a DHCP lease Oct 26 02:27:55 x2 dhcpcd[614]: eth0: soliciting a DHCP lease Oct 26 02:27:56 x2 sh[565]: eth0: soliciting an IPv6 router Oct 26 02:27:56 x2 dhcpcd[614]: eth0: soliciting an IPv6 router Oct 26 02:27:56 x2 ntpd[801]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Oct 26 02:27:56 x2 ifplugd(eth0)[813]: Link beat detected. Oct 26 02:27:56 x2 ifplugd(eth0)[813]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Oct 26 02:27:56 x2 ifplugd(eth0)[813]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Oct 26 02:27:57 x2 bthelper[705]: Changing power off succeeded Oct 26 02:27:57 x2 bthelper[705]: [CHG] Controller DC:A6:32:AC:46:7F Powered: no Oct 26 02:27:57 x2 bthelper[705]: [CHG] Controller DC:A6:32:AC:46:7F Discovering: no Oct 26 02:27:57 x2 bthelper[705]: [CHG] Controller DC:A6:32:AC:46:7F Class: 0x00000000 Oct 26 02:27:57 x2 ntpd[801]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Oct 26 02:27:57 x2 bthelper[705]: [CHG] Controller DC:A6:32:AC:46:7F Class: 0x0000041c Oct 26 02:27:57 x2 bthelper[705]: Changing power on succeeded Oct 26 02:27:58 x2 sudo[865]: pam_unix(sudo:session): session closed for user root Oct 26 02:27:58 x2 wireless.js[684]: SETTING APPROPRIATE REG DOMAIN: GB Oct 26 02:27:58 x2 sudo[882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 26 02:27:58 x2 sudo[882]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:27:58 x2 sudo[882]: pam_unix(sudo:session): session closed for user root Oct 26 02:27:58 x2 sudo[884]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set GB Oct 26 02:27:58 x2 sudo[884]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:27:58 x2 sudo[884]: pam_unix(sudo:session): session closed for user root Oct 26 02:27:58 x2 wireless.js[684]: SUCCESSFULLY SET NEW REGDOMAIN: GB Oct 26 02:27:58 x2 volumio-remote-updater[688]: [2024-10-26 02:27:58] [info] asio async_connect error: system:111 (Connection refused) Oct 26 02:27:58 x2 volumio-remote-updater[688]: [2024-10-26 02:27:58] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 26 02:27:58 x2 volumio-remote-updater[688]: [2024-10-26 02:27:58] [error] handle_connect error: Underlying Transport Error Oct 26 02:27:58 x2 sudo[891]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 26 02:27:58 x2 sudo[891]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:27:58 x2 sudo[891]: pam_unix(sudo:session): session closed for user root Oct 26 02:27:58 x2 sudo[893]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 26 02:27:58 x2 sudo[893]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:27:58 x2 sudo[893]: pam_unix(sudo:session): session closed for user root Oct 26 02:27:58 x2 wireless.js[684]: Hotspot is disabled, not starting it Oct 26 02:27:58 x2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 26 02:27:58 x2 systemd[1]: wireless.service: Succeeded. Oct 26 02:27:58 x2 systemd[1]: Started Wireless Services. Oct 26 02:27:58 x2 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 26 02:27:58 x2 systemd[1]: Started Volumio Backend Module. Oct 26 02:27:59 x2 systemd[1]: Started Volumio Cpu Tweaker. Oct 26 02:27:59 x2 volumio-cpu-tweak[900]: Setting RT Priority for mpd Oct 26 02:27:59 x2 volumio-cpu-tweak[900]: pid 35's current scheduling policy: SCHED_OTHER Oct 26 02:27:59 x2 volumio-cpu-tweak[900]: pid 35's current scheduling priority: 0 Oct 26 02:27:59 x2 volumio-cpu-tweak[900]: Setting MPD Affinity Oct 26 02:27:59 x2 volumio-cpu-tweak[900]: pid 3's current affinity mask: f Oct 26 02:27:59 x2 volumio-cpu-tweak[900]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Oct 26 02:27:59 x2 volumio-cpu-tweak[900]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Oct 26 02:27:59 x2 systemd[1]: volumio_cpu_tweak.service: Succeeded. Oct 26 02:27:59 x2 sh[565]: eth0: offered 192.168.10.81 from 192.168.10.1 Oct 26 02:27:59 x2 dhcpcd[614]: eth0: offered 192.168.10.81 from 192.168.10.1 Oct 26 02:27:59 x2 sh[565]: eth0: ignoring offer of 192.168.10.81 from 192.168.10.1 Oct 26 02:27:59 x2 dhcpcd[614]: eth0: ignoring offer of 192.168.10.81 from 192.168.10.1 Oct 26 02:27:59 x2 sh[565]: eth0: probing address 192.168.10.81/24 Oct 26 02:27:59 x2 dhcpcd[614]: eth0: probing address 192.168.10.81/24 Oct 26 02:28:00 x2 volumio[899]: info: ------------------------------------------- Oct 26 02:28:00 x2 volumio[899]: info: ----- Volumio3 ---- Oct 26 02:28:00 x2 volumio[899]: info: ------------------------------------------- Oct 26 02:28:00 x2 volumio[899]: info: ----- System startup ---- Oct 26 02:28:00 x2 volumio[899]: info: ------------------------------------------- Oct 26 02:28:01 x2 volumio[899]: info: MYVOLUMIO Environment detected Oct 26 02:28:01 x2 volumio[899]: info: Plugin folders cleanup Oct 26 02:28:01 x2 volumio[899]: info: Scanning into folder /volumio/app/plugins/ Oct 26 02:28:01 x2 volumio[899]: info: Scanning category audio_interface Oct 26 02:28:01 x2 volumio[899]: info: Scanning category miscellanea Oct 26 02:28:01 x2 volumio[899]: info: Scanning category music_service Oct 26 02:28:01 x2 volumio[899]: info: Scanning category plugins.json Oct 26 02:28:01 x2 volumio[899]: info: Scanning category system_controller Oct 26 02:28:01 x2 volumio[899]: info: Scanning category user_interface Oct 26 02:28:01 x2 volumio[899]: info: Scanning into folder /data/plugins/ Oct 26 02:28:01 x2 volumio[899]: info: Scanning category audio_interface Oct 26 02:28:01 x2 volumio[899]: info: Scanning category music_service Oct 26 02:28:01 x2 volumio[899]: info: Scanning category system_controller Oct 26 02:28:01 x2 volumio[899]: info: Scanning category user_interface Oct 26 02:28:01 x2 volumio[899]: info: Plugin folders cleanup completed Oct 26 02:28:01 x2 volumio[899]: info: ------------------------------------------- Oct 26 02:28:01 x2 volumio[899]: info: ----- Core plugins startup ---- Oct 26 02:28:01 x2 volumio[899]: info: ------------------------------------------- Oct 26 02:28:01 x2 volumio[899]: info: Loading plugins from folder /volumio/app/plugins/ Oct 26 02:28:01 x2 volumio[899]: info: Adding plugin upnp to MyMusic Plugins Oct 26 02:28:01 x2 volumio[899]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 26 02:28:01 x2 volumio[899]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 26 02:28:01 x2 volumio[899]: info: Loading plugins from folder /data/plugins/ Oct 26 02:28:01 x2 volumio[899]: info: Loading plugin "system"... Oct 26 02:28:01 x2 volumio[899]: info: Loading plugin "appearance"... Oct 26 02:28:02 x2 volumio[899]: info: Loading plugin "network"... Oct 26 02:28:02 x2 volumio[899]: info: Refreshing Cached IP Addresses Oct 26 02:28:02 x2 sudo[930]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 26 02:28:02 x2 sudo[930]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:02 x2 sudo[930]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:02 x2 volumio[899]: info: Loading plugin "services"... Oct 26 02:28:02 x2 sudo[932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 26 02:28:02 x2 sudo[932]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:02 x2 volumio[899]: info: Loading plugin "alsa_controller"... Oct 26 02:28:02 x2 sudo[932]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:02 x2 sudo[935]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 26 02:28:02 x2 sudo[935]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:02 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 26 02:28:02 x2 volumio[899]: info: Loading plugin "wizard"... Oct 26 02:28:02 x2 volumio[899]: info: Loading plugin "networkfs"... Oct 26 02:28:02 x2 volumio[899]: info: Starting Udev Watcher for removable devices Oct 26 02:28:02 x2 sudo[941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=adm1n,password=st123456,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.10.85/Media/Music /mnt/NAS/Tnas Oct 26 02:28:02 x2 sudo[941]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:02 x2 volumio[899]: info: Ignoring mount for partition: boot Oct 26 02:28:02 x2 volumio[899]: info: Ignoring mount for partition: volumio Oct 26 02:28:02 x2 volumio[899]: info: Ignoring mount for partition: volumio_data Oct 26 02:28:02 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 26 02:28:02 x2 volumio[899]: info: Loading plugin "volumio_command_line_client"... Oct 26 02:28:02 x2 volumio[899]: info: Plugin upnp is not enabled Oct 26 02:28:02 x2 volumio[899]: info: Loading plugin "my_music"... Oct 26 02:28:02 x2 volumio[899]: info: Loading plugin "mpd"... Oct 26 02:28:02 x2 sudo[941]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:02 x2 kernel: Key type cifs.spnego registered Oct 26 02:28:02 x2 kernel: Key type cifs.idmap registered Oct 26 02:28:02 x2 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. Oct 26 02:28:02 x2 kernel: CIFS: Attempting to mount \\192.168.10.85\Media Oct 26 02:28:02 x2 kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Oct 26 02:28:02 x2 kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Oct 26 02:28:03 x2 volumio[899]: info: Plugin upnp_browser is not enabled Oct 26 02:28:03 x2 volumio[899]: info: Loading plugin "alarm-clock"... Oct 26 02:28:03 x2 volumio[899]: info: Loading plugin "airplay_emulation"... Oct 26 02:28:03 x2 volumio[899]: info: Starting Shairport Sync Oct 26 02:28:03 x2 volumio[899]: info: Loading plugin "last_100"... Oct 26 02:28:03 x2 volumio[899]: info: Loading plugin "webradio"... Oct 26 02:28:03 x2 volumio[899]: info: Loading plugin "i2s_dacs"... Oct 26 02:28:03 x2 volumio[899]: info: Loading plugin "volumiodiscovery"... Oct 26 02:28:03 x2 volumio[899]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 26 02:28:03 x2 volumio[899]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 26 02:28:03 x2 node[899]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 26 02:28:03 x2 volumio[899]: *** WARNING *** For more information see Oct 26 02:28:03 x2 volumio[899]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 26 02:28:03 x2 volumio[899]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 26 02:28:03 x2 volumio[899]: *** WARNING *** For more information see Oct 26 02:28:03 x2 node[899]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 26 02:28:03 x2 node[899]: *** WARNING *** For more information see Oct 26 02:28:03 x2 node[899]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 26 02:28:03 x2 node[899]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 26 02:28:03 x2 node[899]: *** WARNING *** For more information see Oct 26 02:28:03 x2 volumio[899]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 26 02:28:03 x2 volumio[899]: info: Discovery: Started advertising with name: X2 Oct 26 02:28:03 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 26 02:28:03 x2 volumio[899]: info: Loading plugin "spop"... Oct 26 02:28:04 x2 sh[565]: eth0: leased 192.168.10.81 for 7200 seconds Oct 26 02:28:04 x2 dhcpcd[614]: eth0: leased 192.168.10.81 for 7200 seconds Oct 26 02:28:04 x2 sh[565]: eth0: adding route to 192.168.10.0/24 Oct 26 02:28:04 x2 sh[565]: eth0: adding default route via 192.168.10.1 Oct 26 02:28:04 x2 avahi-daemon[678]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.10.81. Oct 26 02:28:04 x2 avahi-daemon[678]: New relevant interface eth0.IPv4 for mDNS. Oct 26 02:28:04 x2 dhcpcd[614]: eth0: adding route to 192.168.10.0/24 Oct 26 02:28:04 x2 avahi-daemon[678]: Registering new address record for 192.168.10.81 on eth0.IPv4. Oct 26 02:28:04 x2 dhcpcd[614]: eth0: adding default route via 192.168.10.1 Oct 26 02:28:04 x2 ntpd[801]: ntpd exiting on signal 15 (Terminated) Oct 26 02:28:04 x2 systemd[1]: Stopping Network Time Service... Oct 26 02:28:04 x2 systemd[1]: ntp.service: Succeeded. Oct 26 02:28:04 x2 systemd[1]: Stopped Network Time Service. Oct 26 02:28:04 x2 nmbd[787]: [2024/10/26 02:28:04.454439, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 26 02:28:04 x2 nmbd[787]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Oct 26 02:28:04 x2 nmbd[787]: [2024/10/26 02:28:04.470588, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 26 02:28:04 x2 nmbd[787]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.10.81 for name WORKGROUP<1d>. Oct 26 02:28:04 x2 nmbd[787]: This response was from IP 192.168.10.228, reporting an IP address of 192.168.10.228. Oct 26 02:28:04 x2 systemd[1]: Starting Network Time Service... Oct 26 02:28:04 x2 systemd[1]: Started Samba NMB Daemon. Oct 26 02:28:04 x2 systemd[1]: Starting Samba Winbind Daemon... Oct 26 02:28:04 x2 ntpd[987]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 26 02:28:04 x2 ntpd[987]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -c /run/ntp.conf.dhcp -u 103:103 Oct 26 02:28:04 x2 systemd[1]: Started Network Time Service. Oct 26 02:28:04 x2 ntpd[995]: proto: precision = 0.833 usec (-20) Oct 26 02:28:04 x2 ntpd[995]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 26 02:28:04 x2 ntpd[995]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 26 02:28:04 x2 ntpd[995]: Listen and drop on 0 v6wildcard [::]:123 Oct 26 02:28:04 x2 ntpd[995]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 26 02:28:04 x2 ntpd[995]: Listen normally on 2 lo 127.0.0.1:123 Oct 26 02:28:04 x2 sh[565]: forked to background, child pid 996 Oct 26 02:28:04 x2 ntpd[995]: Listen normally on 3 eth0 192.168.10.81:123 Oct 26 02:28:04 x2 ntpd[995]: Listening on routing socket on fd #20 for interface updates Oct 26 02:28:04 x2 ntpd[995]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 26 02:28:04 x2 ntpd[995]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 26 02:28:04 x2 dhcpcd[614]: forked to background, child pid 996 Oct 26 02:28:04 x2 ifplugd(eth0)[813]: client: ifup: interface eth0 already configured Oct 26 02:28:04 x2 sh[565]: eth0=eth0 Oct 26 02:28:04 x2 winbindd[992]: [2024/10/26 02:28:04.747101, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Oct 26 02:28:04 x2 winbindd[992]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Oct 26 02:28:04 x2 ifplugd(eth0)[813]: Program executed successfully. Oct 26 02:28:04 x2 winbindd[992]: [2024/10/26 02:28:04.810274, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 26 02:28:04 x2 systemd[1]: Started Samba Winbind Daemon. Oct 26 02:28:04 x2 winbindd[992]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Oct 26 02:28:04 x2 volumio[899]: info: Loading plugin "now_playing"... Oct 26 02:28:04 x2 systemd[1]: Starting Samba SMB Daemon... Oct 26 02:28:05 x2 sudo[935]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:05 x2 smbd[1026]: [2024/10/26 02:28:05.262252, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 26 02:28:05 x2 smbd[1026]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Oct 26 02:28:05 x2 systemd[1]: Started Samba SMB Daemon. Oct 26 02:28:05 x2 systemd[1]: Reached target Multi-User System. Oct 26 02:28:05 x2 systemd[1]: Reached target Graphical Interface. Oct 26 02:28:05 x2 systemd[1]: Starting Update UTMP about System Runlevel Changes... Oct 26 02:28:05 x2 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Oct 26 02:28:05 x2 systemd[1]: Started Update UTMP about System Runlevel Changes. Oct 26 02:28:05 x2 systemd[1]: Startup finished in 21.398s (kernel) + 20.152s (userspace) = 41.551s. Oct 26 02:28:05 x2 ntpd[995]: Soliciting pool server 217.114.59.3 Oct 26 02:28:05 x2 volumio-remote-updater[688]: [2024-10-26 02:28:05] [connect] Successful connection Oct 26 02:28:06 x2 volumio[899]: info: Loading plugin "outputs"... Oct 26 02:28:06 x2 volumio[899]: info: Loading plugin "albumart"... Oct 26 02:28:06 x2 volumio[899]: info: Plugin example_plugin is not enabled Oct 26 02:28:06 x2 volumio[899]: info: Loading plugin "inputs"... Oct 26 02:28:06 x2 volumio[899]: info: Loading plugin "updater_comm"... Oct 26 02:28:06 x2 volumio[899]: info: Plugin mpdemulation is not enabled Oct 26 02:28:06 x2 volumio[899]: info: Loading plugin "rest_api"... Oct 26 02:28:06 x2 volumio[899]: info: Loading plugin "websocket"... Oct 26 02:28:06 x2 volumio[899]: info: Starting Socket.io Server version 2.3.0 Oct 26 02:28:06 x2 volumio[899]: info: Loading plugin "fusiondsp"... Oct 26 02:28:06 x2 volumio[899]: Forking 3 albumart workers Oct 26 02:28:06 x2 ntpd[995]: Soliciting pool server 93.93.131.118 Oct 26 02:28:06 x2 ntpd[995]: Soliciting pool server 139.162.219.252 Oct 26 02:28:06 x2 volumio[899]: info: Applying required configuration parameters for plugin fusiondsp Oct 26 02:28:06 x2 volumio[899]: info: Loading plugin "backup_restore"... Oct 26 02:28:06 x2 volumio[899]: Starting albumart workers Oct 26 02:28:07 x2 volumio[899]: Starting albumart workers Oct 26 02:28:07 x2 volumio[899]: Starting albumart workers Oct 26 02:28:07 x2 volumio[899]: info: Applying required configuration parameters for plugin backup_restore Oct 26 02:28:07 x2 volumio[899]: info: Plugin lastfm is not enabled Oct 26 02:28:07 x2 volumio[899]: info: Loading plugin "peppymeterbasic"... Oct 26 02:28:07 x2 ntpd[995]: Soliciting pool server 139.143.5.30 Oct 26 02:28:07 x2 ntpd[995]: Soliciting pool server 82.219.4.30 Oct 26 02:28:07 x2 ntpd[995]: Soliciting pool server 131.111.8.61 Oct 26 02:28:07 x2 volumio[899]: info: Plugin peppyspectrum is not enabled Oct 26 02:28:07 x2 volumio[899]: info: Loading plugin "touch_display"... Oct 26 02:28:07 x2 volumio[899]: info: Applying required configuration parameters for plugin touch_display Oct 26 02:28:08 x2 volumio[899]: info: Loading i18n strings for locale en Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Oct 26 02:28:08 x2 volumio[899]: Updating browse sources language Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::initPlayerControls Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 02:28:08 x2 volumio[899]: Express server listening on port 3000 Oct 26 02:28:08 x2 volumio[899]: [Metrics] WebUI: 8s 160.68ms Oct 26 02:28:08 x2 volumio[899]: info: CoreStateMachine::resetVolumioState Oct 26 02:28:08 x2 volumio[899]: info: CoreStateMachine::getcurrentVolume Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::volumioRetrievevolume Oct 26 02:28:08 x2 volumio[899]: info: Cannot mount NAS Tnas at system boot, trial number 1 ,retrying in 5 seconds Oct 26 02:28:08 x2 volumio-remote-updater[688]: [2024-10-26 02:28:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1729906085 101 Oct 26 02:28:08 x2 volumio[899]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Oct 26 02:28:08 x2 volumio[899]: info: CoreStateMachine::pushState Oct 26 02:28:08 x2 volumio[899]: info: CorePlayQueue::getTrack 0 Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::volumioPushState Oct 26 02:28:08 x2 volumio[899]: info: CoreStateMachine::updateTrackBlock Oct 26 02:28:08 x2 volumio[899]: info: CorePlayQueue::getTrackBlock Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::volumioRetrievevolume Oct 26 02:28:08 x2 volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 26 02:28:08 x2 volumio[899]: info: Reloading queue from file Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: Executing start script for DAC IQaudIO DAC Plus Oct 26 02:28:08 x2 volumio[899]: info: CoreStateMachine::setRepeat null single undefined Oct 26 02:28:08 x2 volumio[899]: info: CoreStateMachine::pushState Oct 26 02:28:08 x2 volumio[899]: info: CorePlayQueue::getTrack 0 Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::volumioPushState Oct 26 02:28:08 x2 ntpd[995]: Soliciting pool server 176.58.109.199 Oct 26 02:28:08 x2 ntpd[995]: Soliciting pool server 185.53.45.4 Oct 26 02:28:08 x2 ntpd[995]: Soliciting pool server 85.199.214.98 Oct 26 02:28:08 x2 volumio[899]: info: CoreStateMachine::setRandom null Oct 26 02:28:08 x2 volumio[899]: info: CoreStateMachine::pushState Oct 26 02:28:08 x2 volumio[899]: info: CorePlayQueue::getTrack 0 Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::volumioPushState Oct 26 02:28:08 x2 volumio[899]: info: Setting Device type: Raspberry PI Oct 26 02:28:08 x2 volumio[899]: info: DAC script executed Oct 26 02:28:08 x2 volumio[899]: info: Completed loading Core Plugins Oct 26 02:28:08 x2 volumio[899]: info: Preparing to generate the ALSA configuration file Oct 26 02:28:08 x2 volumio[899]: info: CoreStateMachine::pushState Oct 26 02:28:08 x2 volumio[899]: info: CorePlayQueue::getTrack 0 Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::volumioPushState Oct 26 02:28:08 x2 volumio[899]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 26 02:28:08 x2 volumio[899]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 26 02:28:08 x2 volumio[899]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 26 02:28:08 x2 volumio[899]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 26 02:28:08 x2 volumio[899]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 26 02:28:08 x2 volumio[899]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Oct 26 02:28:08 x2 volumio[899]: info: Reading ALSA contributions from plugins. Oct 26 02:28:08 x2 ntpd[995]: Soliciting pool server 193.57.144.50 Oct 26 02:28:08 x2 volumio[899]: info: Asound.conf file unchanged, so no further update is needed Oct 26 02:28:08 x2 volumio[899]: info: Output device has changed, restarting MPD Oct 26 02:28:08 x2 sudo[1112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 26 02:28:08 x2 volumio[899]: info: Output device has changed, restarting Shairport Sync Oct 26 02:28:08 x2 sudo[1112]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:08 x2 sudo[1112]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:08 x2 sudo[1115]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 26 02:28:08 x2 sudo[1115]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:08 x2 volumio[899]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 26 02:28:08 x2 volumio[899]: info: ___________ START PLUGINS ___________ Oct 26 02:28:08 x2 volumio[899]: info: ControllerMpd::onStart: Initializing MPD Oct 26 02:28:08 x2 volumio[899]: info: Creating MPD Configuration file Oct 26 02:28:08 x2 sudo[1122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 26 02:28:08 x2 sudo[1122]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:08 x2 sudo[1122]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:08 x2 sudo[1124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 26 02:28:08 x2 sudo[1124]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:08 x2 systemd[1]: Listening on mpd.socket. Oct 26 02:28:08 x2 systemd[1]: Starting Music Player Daemon... Oct 26 02:28:08 x2 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 26 02:28:08 x2 systemd[1]: mpd.service: Succeeded. Oct 26 02:28:08 x2 systemd[1]: Stopped Music Player Daemon. Oct 26 02:28:08 x2 systemd[1]: Starting Music Player Daemon... Oct 26 02:28:08 x2 volumio[899]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 26 02:28:08 x2 volumio[899]: info: [1729906088804] CoreMusicLibrary::Adding element Last_100 Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 26 02:28:08 x2 volumio[899]: info: [1729906088809] CoreMusicLibrary::Adding element Webradio Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 26 02:28:08 x2 volumio[899]: info: Initializing BBC Radios Oct 26 02:28:08 x2 sudo[1134]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 26 02:28:08 x2 sudo[1134]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:08 x2 sudo[1134]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 26 02:28:08 x2 sudo[1134]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: Creating Spotify config file Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: [now-playing] ConfigUpdater: config is up to date. Oct 26 02:28:08 x2 volumio[899]: info: Loading i18n strings for locale en Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:08 x2 volumio[899]: info: FusionDsp - mixtype--------------------- Software Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Oct 26 02:28:08 x2 volumio[899]: info: Loading i18n strings for locale en Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Oct 26 02:28:08 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 26 02:28:08 x2 volumio[899]: info: Volumio Calling Home Oct 26 02:28:09 x2 volumio[899]: info: Preparing to generate the ALSA configuration file Oct 26 02:28:09 x2 sudo[1151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Oct 26 02:28:09 x2 sudo[1151]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 sudo[1153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Oct 26 02:28:09 x2 sudo[1153]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 sudo[1157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Oct 26 02:28:09 x2 sudo[1157]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 volumio[899]: info: [now-playing] Fetching API key... Oct 26 02:28:09 x2 volumio[899]: info: [now-playing] App is listening on port 4004. Oct 26 02:28:09 x2 volumio[899]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Oct 26 02:28:09 x2 volumio[899]: info: Discovery: adding 356ec9ff-4742-4a55-8c38-53c3b5930d80 Oct 26 02:28:09 x2 volumio[899]: info: Discovery: Found device X2 Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::volumioGetState Oct 26 02:28:09 x2 volumio[899]: info: CorePlayQueue::getTrack 0 Oct 26 02:28:09 x2 volumio[899]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 26 02:28:09 x2 volumio[899]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 26 02:28:09 x2 volumio[899]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Oct 26 02:28:09 x2 volumio[899]: info: Reading ALSA contributions from plugins. Oct 26 02:28:09 x2 volumio[899]: info: touch_display: Backlight interface detected. Oct 26 02:28:09 x2 volumio[899]: info: MPD Permissions set Oct 26 02:28:09 x2 volumio[899]: info: MPD Permissions set Oct 26 02:28:09 x2 systemd[1]: Reloading. Oct 26 02:28:09 x2 volumio[899]: info: Volumio called home Oct 26 02:28:09 x2 volumio[899]: info: Spotify config file written Oct 26 02:28:09 x2 sudo[1160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 26 02:28:09 x2 volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Oct 26 02:28:09 x2 sudo[1160]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: No need to fix Spotify hosts Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 ntpd[995]: Soliciting pool server 131.111.8.63 Oct 26 02:28:09 x2 ntpd[995]: Soliciting pool server 162.159.200.123 Oct 26 02:28:09 x2 ntpd[995]: Soliciting pool server 85.199.214.100 Oct 26 02:28:09 x2 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. Oct 26 02:28:09 x2 volumio[899]: info: touch_display: Raspberry Pi Foundation touch screen detected. Oct 26 02:28:09 x2 sudo[1184]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Oct 26 02:28:09 x2 sudo[1184]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 sudo[1184]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:09 x2 ntpd[995]: Soliciting pool server 213.5.132.231 Oct 26 02:28:09 x2 sudo[1187]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Oct 26 02:28:09 x2 sudo[1187]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 sudo[1187]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:09 x2 volumio[899]: info: Starting Shairport Sync Oct 26 02:28:09 x2 volumio[899]: info: Starting Shairport Sync Oct 26 02:28:09 x2 sudo[1190]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 26 02:28:09 x2 volumio[899]: info: Starting Shairport Sync Oct 26 02:28:09 x2 sudo[1190]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 sudo[1192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 26 02:28:09 x2 sudo[1192]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 sudo[1195]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 26 02:28:09 x2 sudo[1195]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::volumioGetState Oct 26 02:28:09 x2 volumio[899]: info: CorePlayQueue::getTrack 0 Oct 26 02:28:09 x2 volumio[899]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Oct 26 02:28:09 x2 volumio[899]: info: touch_display: File permissions for backlight brightness control set. Oct 26 02:28:09 x2 volumio[899]: info: Asound.conf file unchanged, so no further update is needed Oct 26 02:28:09 x2 volumio[899]: info: Output device has changed, restarting MPD Oct 26 02:28:09 x2 volumio[899]: info: Output device has changed, restarting Shairport Sync Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:09 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:09 x2 sudo[1199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 26 02:28:09 x2 sudo[1199]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 sudo[1199]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:09 x2 sudo[1201]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 26 02:28:09 x2 sudo[1201]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:09 x2 volumio[899]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 26 02:28:09 x2 volumio[899]: info: Preparing to generate the ALSA configuration file Oct 26 02:28:09 x2 volumio[899]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 26 02:28:09 x2 volumio[899]: SPOTIFY: BQCBuGUzCtdIpNW-rvHz1RILAiaon1XG7S7ZkBSCvendGS8i-cBCYnYP6zscB4gLZNs3LuGZgepGUvwWMVHY4Ejg0ctS0knu1VE6j9UkUhoW_m6dxE4GRa6r0aSo-eYTw14imoWdMTCY4xi-0C5QC5oHalJqaYVK5dVApD4srkxgY1Ahve589yTRJyVknqrTndVjZp7Fcil5o2lU05R1svqcI9AqYajlsjxY6NoXuyQ7x6KhHGIXFWo Oct 26 02:28:09 x2 volumio[899]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 26 02:28:09 x2 volumio[899]: info: New Spotify access token = BQCBuGUzCtdIpNW-rvHz1RILAiaon1XG7S7ZkBSCvendGS8i-cBCYnYP6zscB4gLZNs3LuGZgepGUvwWMVHY4Ejg0ctS0knu1VE6j9UkUhoW_m6dxE4GRa6r0aSo-eYTw14imoWdMTCY4xi-0C5QC5oHalJqaYVK5dVApD4srkxgY1Ahve589yTRJyVknqrTndVjZp7Fcil5o2lU05R1svqcI9AqYajlsjxY6NoXuyQ7x6KhHGIXFWo Oct 26 02:28:09 x2 volumio[899]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 26 02:28:09 x2 volumio[899]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 26 02:28:09 x2 volumio[899]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 26 02:28:09 x2 volumio[899]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Oct 26 02:28:09 x2 volumio[899]: info: Reading ALSA contributions from plugins. Oct 26 02:28:09 x2 sudo[1157]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:09 x2 sudo[1151]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:09 x2 systemd[1]: Reloading. Oct 26 02:28:09 x2 volumio[899]: info: MPD Permissions set Oct 26 02:28:09 x2 volumio[899]: info: touch_display: systemctl stop getty@tty1.service succeeded. Oct 26 02:28:09 x2 volumio[899]: info: touch_display: systemctl daemon-reload succeeded. Oct 26 02:28:10 x2 sudo[1211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Oct 26 02:28:10 x2 sudo[1211]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: Starting Shairport Sync Oct 26 02:28:10 x2 volumio[899]: info: Asound.conf file unchanged, so no further update is needed Oct 26 02:28:10 x2 volumio[899]: info: Output device has changed, restarting MPD Oct 26 02:28:10 x2 sudo[1231]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 26 02:28:10 x2 sudo[1231]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:10 x2 volumio[899]: info: Output device has changed, restarting Shairport Sync Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:10 x2 sudo[1235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 26 02:28:10 x2 sudo[1235]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:10 x2 sudo[1235]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:10 x2 sudo[1237]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 26 02:28:10 x2 sudo[1237]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:10 x2 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. Oct 26 02:28:10 x2 volumio[899]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 26 02:28:10 x2 volumio[899]: info: MPD Permissions set Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:10 x2 volumio[899]: info: Starting Shairport Sync Oct 26 02:28:10 x2 volumio[899]: SPOTIFY: User informations: {"country":"GB","display_name":"googled","email":"gauss0@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/googled"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/googled","id":"googled","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee850391b95f952bebf796c85077","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b820391b95f952bebf796c85077","width":64}],"product":"premium","type":"user","uri":"spotify:user:googled"} Oct 26 02:28:10 x2 volumio[899]: info: Spotify Successfully logged in Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 26 02:28:10 x2 volumio[899]: info: [1729906090350] CoreMusicLibrary::Adding element Spotify Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 26 02:28:10 x2 volumio[899]: Cannot find translation for source Spotify Oct 26 02:28:10 x2 sudo[1250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 26 02:28:10 x2 sudo[1250]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:10 x2 ntpd[995]: Soliciting pool server 162.159.200.1 Oct 26 02:28:10 x2 ntpd[995]: Soliciting pool server 149.22.220.130 Oct 26 02:28:10 x2 ntpd[995]: Soliciting pool server 95.215.175.2 Oct 26 02:28:10 x2 sudo[1153]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:10 x2 ntpd[995]: Soliciting pool server 185.103.119.60 Oct 26 02:28:10 x2 volumio[899]: info: [now-playing] OpenWeatherMap API key obtained. Oct 26 02:28:10 x2 volumio[899]: info: touch_display: systemctl disable getty@tty1.service succeeded. Oct 26 02:28:10 x2 systemd[1]: Started Volumio Kiosk. Oct 26 02:28:10 x2 sudo[1211]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:10 x2 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 26 02:28:10 x2 volumio[899]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Oct 26 02:28:10 x2 volumio[899]: info: touch_display: Volumio Kiosk started. Oct 26 02:28:10 x2 systemd[1]: Started go-librespot Daemon. Oct 26 02:28:10 x2 sudo[1160]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:10 x2 go-librespot[1254]: Librespot-go daemon starting... Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::volumioGetState Oct 26 02:28:10 x2 volumio[899]: info: CorePlayQueue::getTrack 0 Oct 26 02:28:10 x2 systemd[1]: shairport-sync.service: Succeeded. Oct 26 02:28:10 x2 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 26 02:28:10 x2 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 26 02:28:10 x2 systemd[1]: mpd.service: Succeeded. Oct 26 02:28:10 x2 systemd[1]: Stopped Music Player Daemon. Oct 26 02:28:10 x2 volumio[899]: info: CoreCommandRouter::volumioGetState Oct 26 02:28:10 x2 volumio[899]: info: CorePlayQueue::getTrack 0 Oct 26 02:28:10 x2 systemd[1]: Starting Music Player Daemon... Oct 26 02:28:10 x2 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 26 02:28:10 x2 volumio[899]: error: [now-playing] Error fetching https://openweathermap.org/data/2.5/onecall?appid=5796abbde9106b7da4febfae8c44c232&lat=54&lon=-1: Error: Response error: 401 - Unauthorized Oct 26 02:28:10 x2 volumio[899]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Oct 26 02:28:10 x2 volumio[899]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Oct 26 02:28:10 x2 volumio[899]: at async Promise.all (index 0) Oct 26 02:28:10 x2 volumio[899]: at async fetchData (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:84:24) Oct 26 02:28:10 x2 volumio[899]: at async OpenWeatherMapAPI.getWeather (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:97:45) Oct 26 02:28:10 x2 volumio[899]: at async /data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:297:25 Oct 26 02:28:10 x2 volumio[899]: info: [now-playing] Fetching API key... Oct 26 02:28:10 x2 sudo[1231]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:10 x2 sudo[1192]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:10 x2 sudo[1190]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:10 x2 sudo[1250]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:10 x2 sudo[1195]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:10 x2 volumio[899]: error: [now-playing] Error fetching https://openweathermap.org/data/2.5/weather?appid=5796abbde9106b7da4febfae8c44c232&lat=54&lon=-1: Error: Response error: 401 - Unauthorized Oct 26 02:28:10 x2 volumio[899]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Oct 26 02:28:10 x2 volumio[899]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Oct 26 02:28:10 x2 volumio[899]: at async Promise.all (index 1) Oct 26 02:28:10 x2 volumio[899]: info: Shairport-Sync Started Oct 26 02:28:10 x2 volumio[899]: Error adding Membership: Error: addMembership EINVAL Oct 26 02:28:10 x2 volumio[899]: info: touch_display: X display number found: Oct 26 02:28:10 x2 volumio[899]: info: Shairport-Sync Started Oct 26 02:28:10 x2 volumio[899]: info: Shairport-Sync Started Oct 26 02:28:10 x2 volumio[899]: info: Shairport-Sync Started Oct 26 02:28:10 x2 volumio[899]: info: Shairport-Sync Started Oct 26 02:28:10 x2 sudo[1269]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 26 02:28:10 x2 sudo[1269]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:10 x2 sudo[1269]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 26 02:28:10 x2 sudo[1269]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:10 x2 volumio[899]: info: touch_display: X display number found: 0 Oct 26 02:28:11 x2 volumio[899]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Oct 26 02:28:11 x2 volumio[899]: info: camilladsp service started and running in background, instance 1 Oct 26 02:28:11 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 02:28:11 x2 volumio[899]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Oct 26 02:28:11 x2 volumio[899]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Oct 26 02:28:11 x2 volumio[899]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Oct 26 02:28:11 x2 volumio[899]: info: FusionDsp loaded Oct 26 02:28:11 x2 volumio[899]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 02:28:11 x2 startx[1252]: X.Org X Server 1.20.4 Oct 26 02:28:11 x2 startx[1252]: X Protocol Version 11, Revision 0 Oct 26 02:28:11 x2 startx[1252]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Oct 26 02:28:11 x2 startx[1252]: Current Operating System: Linux x2 6.1.69-v7l+ #1710 SMP Thu Dec 21 13:17:38 GMT 2023 armv7l Oct 26 02:28:11 x2 startx[1252]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:AC:46:7D 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=8543fa12-4125-4451-a534-cec5480e0606 imgfile=/volumio_current.sqsh bootpart=UUID=9C48-E5A3 datapart=UUID=e4f90c9a-0640-4e33-ba44-2039c5abd3b8 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 Oct 26 02:28:11 x2 startx[1252]: Build Date: 04 April 2023 07:50:56AM Oct 26 02:28:11 x2 startx[1252]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Oct 26 02:28:11 x2 startx[1252]: Current version of pixman: 0.36.0 Oct 26 02:28:11 x2 startx[1252]: Before reporting problems, check http://wiki.x.org Oct 26 02:28:11 x2 startx[1252]: to make sure that you have the latest version. Oct 26 02:28:11 x2 startx[1252]: Markers: (--) probed, (**) from config file, (==) default setting, Oct 26 02:28:11 x2 startx[1252]: (++) from command line, (!!) notice, (II) informational, Oct 26 02:28:11 x2 startx[1252]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Oct 26 02:28:11 x2 startx[1252]: (==) Log file: "/var/log/Xorg.0.log", Time: Sat Oct 26 02:28:11 2024 Oct 26 02:28:11 x2 sudo[1304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Oct 26 02:28:11 x2 startx[1252]: (==) Using config directory: "/etc/X11/xorg.conf.d" Oct 26 02:28:11 x2 startx[1252]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Oct 26 02:28:11 x2 sudo[1304]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 02:28:11 x2 volumio[899]: info: FusionDsp - Reporting Fusion DSP Enabled Oct 26 02:28:11 x2 volumio[899]: info: Adding Signal Path Element [object Object] Oct 26 02:28:11 x2 volumio[899]: info: Adding fusiondspeq DSP Signal Path Element Oct 26 02:28:11 x2 volumio[899]: info: FusionDsp - ---- installed callbackRead Oct 26 02:28:11 x2 volumio[899]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 02:28:11 x2 volumio[899]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Oct 26 02:28:11 x2 volumio[899]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) Oct 26 02:28:11 x2 volumio[899]: at onErrorNT (internal/child_process.js:465:16) Oct 26 02:28:11 x2 volumio[899]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 26 02:28:11 x2 volumio[899]: at runNextTicks (internal/process/task_queues.js:62:3) Oct 26 02:28:11 x2 volumio[899]: at listOnTimeout (internal/timers.js:523:9) Oct 26 02:28:11 x2 volumio[899]: at processTimers (internal/timers.js:497:7) { Oct 26 02:28:11 x2 volumio[899]: errno: -2, Oct 26 02:28:11 x2 volumio[899]: code: 'ENOENT', Oct 26 02:28:11 x2 volumio[899]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Oct 26 02:28:11 x2 volumio[899]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Oct 26 02:28:11 x2 volumio[899]: spawnargs: [ Oct 26 02:28:11 x2 volumio[899]: '-p', Oct 26 02:28:11 x2 volumio[899]: 9876, Oct 26 02:28:11 x2 volumio[899]: '-o', Oct 26 02:28:11 x2 volumio[899]: '/tmp/camilladsp.log', Oct 26 02:28:11 x2 volumio[899]: '-l', Oct 26 02:28:11 x2 volumio[899]: 'warn', Oct 26 02:28:11 x2 volumio[899]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Oct 26 02:28:11 x2 volumio[899]: ] Oct 26 02:28:11 x2 volumio[899]: } Oct 26 02:28:11 x2 volumio[899]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 02:28:11 x2 systemd[1]: Started FusionDsp Daemon. Oct 26 02:28:11 x2 go-librespot[1254]: time="2024-10-26T02:28:11+01:00" level=info msg="generated new device id: fb92e71bd17a9f51ab0aee351bb453855682ab38" Oct 26 02:28:11 x2 go-librespot[1254]: time="2024-10-26T02:28:11+01:00" level=debug msg="stored credentials found for googled" Oct 26 02:28:11 x2 sudo[1304]: pam_unix(sudo:session): session closed for user root Oct 26 02:28:11 x2 sudo[1316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-26 02:27 Oct 26 02:28:11 x2 sudo[1316]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"