-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2024-09-01 16:41:15 CEST. -- Sep 01 16:40:22 roland fake-hwclock[286]: Sun Sep 1 14:40:22 UTC 2024 Sep 01 16:40:22 roland systemd[1]: Mounted POSIX Message Queue File System. Sep 01 16:40:22 roland systemd[1]: Started Remount Root and Kernel File Systems. Sep 01 16:40:22 roland systemd[1]: Mounted RPC Pipe File System. Sep 01 16:40:22 roland systemd[1]: Mounted Kernel Debug File System. Sep 01 16:40:22 roland systemd[1]: Started Restore / save the current clock. Sep 01 16:40:22 roland systemd[1]: Starting Load/Save Random Seed... Sep 01 16:40:22 roland systemd[1]: Starting Create System Users... Sep 01 16:40:22 roland systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Sep 01 16:40:22 roland systemd[1]: Started Create list of required static device nodes for the current kernel. Sep 01 16:40:22 roland systemd[1]: Started Load/Save Random Seed. Sep 01 16:40:22 roland systemd-modules-load[293]: Inserted module 'i2c_dev' Sep 01 16:40:22 roland kernel: i2c_dev: i2c /dev entries driver Sep 01 16:40:22 roland systemd[1]: Started Load Kernel Modules. Sep 01 16:40:22 roland volumio[278]: 512 MB or less RAM Detected, need to enable swap Sep 01 16:40:22 roland systemd[1]: Starting Apply Kernel Variables... Sep 01 16:40:22 roland systemd[1]: Mounting Kernel Configuration File System... Sep 01 16:40:22 roland systemd[1]: Mounting FUSE Control File System... Sep 01 16:40:22 roland systemd[1]: Started udev Coldplug all Devices. Sep 01 16:40:22 roland systemd[1]: Starting Helper to synchronize boot up for ifupdown... Sep 01 16:40:22 roland systemd[1]: Started Create System Users. Sep 01 16:40:22 roland systemd[1]: Mounted Kernel Configuration File System. Sep 01 16:40:22 roland systemd[1]: Mounted FUSE Control File System. Sep 01 16:40:22 roland kernel: ext4 filesystem being mounted at /swap supports timestamps until 2038 (0x7fffffff) Sep 01 16:40:22 roland systemd[1]: Starting Create Static Device Nodes in /dev... Sep 01 16:40:22 roland volumio[278]: Enabling Swap Sep 01 16:40:22 roland volumio[278]: Setting swappiness to 40 Sep 01 16:40:22 roland kernel: Adding 524260k swap on /swap/swapfile. Priority:-2 extents:6 across:6965244k SSFS Sep 01 16:40:22 roland systemd[1]: Started Apply Kernel Variables. Sep 01 16:40:22 roland systemd[1]: Started Helper to synchronize boot up for ifupdown. Sep 01 16:40:22 roland systemd[1]: Started Create Static Device Nodes in /dev. Sep 01 16:40:22 roland systemd[1]: Reached target Local File Systems (Pre). Sep 01 16:40:22 roland systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Sep 01 16:40:22 roland volumio[278]: vm.swappiness = 40 Sep 01 16:40:22 roland systemd[1]: Mounting /var/log... Sep 01 16:40:22 roland systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Sep 01 16:40:22 roland systemd[1]: Mounting /tmp... Sep 01 16:40:22 roland systemd[1]: Mounting /var/spool/cups... Sep 01 16:40:22 roland systemd[1]: Starting udev Kernel Device Manager... Sep 01 16:40:22 roland systemd[1]: dynamicswap.service: Succeeded. Sep 01 16:40:22 roland systemd[1]: Mounted /var/log. Sep 01 16:40:22 roland systemd[1]: Mounted /tmp. Sep 01 16:40:22 roland systemd[1]: Mounted /var/spool/cups. Sep 01 16:40:22 roland systemd[1]: Mounting /var/spool/cups/tmp... Sep 01 16:40:22 roland systemd[1]: Starting Flush Journal to Persistent Storage... Sep 01 16:40:22 roland systemd[1]: Mounted /var/spool/cups/tmp. Sep 01 16:40:22 roland systemd-udevd[337]: Network interface NamePolicy= disabled on kernel command line, ignoring. Sep 01 16:40:22 roland systemd-journald[282]: Runtime journal (/run/log/journal/c28a768762e55f60d289ca8f665f5f47) is 7.5M, max 30.0M, 22.5M free. Sep 01 16:40:22 roland systemd[1]: Started Flush Journal to Persistent Storage. Sep 01 16:40:22 roland systemd[1]: Started udev Kernel Device Manager. Sep 01 16:40:22 roland systemd[1]: Starting Show Plymouth Boot Screen... Sep 01 16:40:22 roland systemd[1]: plymouth-start.service: Succeeded. Sep 01 16:40:22 roland systemd[1]: Started Show Plymouth Boot Screen. Sep 01 16:40:22 roland systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Sep 01 16:40:22 roland systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Sep 01 16:40:22 roland systemd[1]: Reached target Local Encrypted Volumes. Sep 01 16:40:22 roland systemd[1]: Reached target Paths. Sep 01 16:40:23 roland kernel: rpi-gpiomem 3f200000.gpiomem: window base 0x3f200000 size 0x00001000 Sep 01 16:40:23 roland kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Sep 01 16:40:23 roland kernel: rpi-gpiomem 3f200000.gpiomem: initialised 1 regions as /dev/gpiomem Sep 01 16:40:23 roland kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Sep 01 16:40:23 roland kernel: [vc_sm_connected_init]: start Sep 01 16:40:23 roland kernel: mc: Linux media interface: v0.10 Sep 01 16:40:23 roland kernel: [vc_sm_connected_init]: installed successfully Sep 01 16:40:23 roland kernel: videodev: Linux video capture interface: v2.00 Sep 01 16:40:23 roland kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Sep 01 16:40:23 roland kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Sep 01 16:40:23 roland kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Sep 01 16:40:23 roland kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Sep 01 16:40:23 roland systemd[1]: Found device /dev/disk/by-uuid/FD90-ED9E. Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Sep 01 16:40:23 roland kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Sep 01 16:40:23 roland kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Sep 01 16:40:23 roland kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Sep 01 16:40:23 roland kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Sep 01 16:40:23 roland kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Sep 01 16:40:23 roland kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Sep 01 16:40:23 roland kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Sep 01 16:40:23 roland kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Sep 01 16:40:23 roland kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Sep 01 16:40:23 roland kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Sep 01 16:40:23 roland kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Sep 01 16:40:23 roland kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Sep 01 16:40:23 roland kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Sep 01 16:40:23 roland kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Sep 01 16:40:23 roland kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Sep 01 16:40:24 roland kernel: Bluetooth: Core ver 2.22 Sep 01 16:40:24 roland kernel: NET: Registered PF_BLUETOOTH protocol family Sep 01 16:40:24 roland kernel: Bluetooth: HCI device and connection manager initialized Sep 01 16:40:24 roland kernel: Bluetooth: HCI socket layer initialized Sep 01 16:40:24 roland kernel: Bluetooth: L2CAP socket layer initialized Sep 01 16:40:24 roland kernel: Bluetooth: SCO socket layer initialized Sep 01 16:40:24 roland kernel: Bluetooth: HCI UART driver ver 2.3 Sep 01 16:40:24 roland kernel: Bluetooth: HCI UART protocol H4 registered Sep 01 16:40:24 roland kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Sep 01 16:40:24 roland kernel: Bluetooth: HCI UART protocol Broadcom registered Sep 01 16:40:24 roland kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Sep 01 16:40:24 roland kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Sep 01 16:40:24 roland systemd[1]: Starting File System Check on /dev/disk/by-uuid/FD90-ED9E... Sep 01 16:40:24 roland kernel: uart-pl011 3f201000.serial: no DMA platform data Sep 01 16:40:24 roland systemd-udevd[345]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Sep 01 16:40:24 roland kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Sep 01 16:40:24 roland kernel: Bluetooth: hci0: BCM: chip id 94 Sep 01 16:40:24 roland kernel: Bluetooth: hci0: BCM: features 0x2e Sep 01 16:40:24 roland kernel: Bluetooth: hci0: BCM43430A1 Sep 01 16:40:24 roland kernel: Bluetooth: hci0: BCM43430A1 (001.002.009) build 0000 Sep 01 16:40:24 roland kernel: Bluetooth: hci0: BCM43430A1 'brcm/BCM43430A1.hcd' Patch Sep 01 16:40:24 roland kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Sep 01 16:40:24 roland kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Sep 01 16:40:24 roland kernel: cfg80211: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600' Sep 01 16:40:24 roland kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Sep 01 16:40:24 roland systemd-fsck[402]: fsck.fat 4.1 (2017-01-24) Sep 01 16:40:24 roland systemd-fsck[402]: /dev/mmcblk0p1: 366 files, 134023/184582 clusters Sep 01 16:40:24 roland systemd[1]: Started File System Check on /dev/disk/by-uuid/FD90-ED9E. Sep 01 16:40:25 roland kernel: brcmfmac: F1 signature read @0x18000000=0x1541a9a6 Sep 01 16:40:25 roland kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1 Sep 01 16:40:25 roland kernel: usbcore: registered new interface driver brcmfmac Sep 01 16:40:25 roland kernel: brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43430-sdio.raspberrypi,model-zero-2-w.bin failed with error -2 Sep 01 16:40:25 roland kernel: Bluetooth: hci0: BCM: features 0x2e Sep 01 16:40:25 roland kernel: Bluetooth: hci0: BCM43438A1 37.4MHz Raspberry Pi 3-0141 Sep 01 16:40:25 roland kernel: Bluetooth: hci0: BCM43430A1 (001.002.009) build 0508 Sep 01 16:40:25 roland kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Jul 19 2021 03:24:18 version 7.45.98 (TOB) (56df937 CY) FWID 01-8e14b897 Sep 01 16:40:25 roland systemd-udevd[353]: Using default interface naming scheme 'v240'. Sep 01 16:40:25 roland systemd-udevd[353]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Sep 01 16:40:25 roland systemd[1]: Created slice system-bthelper.slice. Sep 01 16:40:25 roland systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Sep 01 16:40:25 roland systemd[1]: Starting Show Plymouth Boot Screen... Sep 01 16:40:25 roland systemd[1]: Condition check resulted in Huge Pages File System being skipped. Sep 01 16:40:25 roland systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Sep 01 16:40:25 roland systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Sep 01 16:40:25 roland systemd[1]: Mounting /boot... Sep 01 16:40:25 roland systemd[1]: Started File System Check Daemon to report status. Sep 01 16:40:25 roland systemd[1]: Mounted /boot. Sep 01 16:40:25 roland systemd[1]: plymouth-start.service: Succeeded. Sep 01 16:40:25 roland systemd[1]: Started Show Plymouth Boot Screen. Sep 01 16:40:25 roland systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Sep 01 16:40:25 roland systemd[1]: Reached target Local File Systems. Sep 01 16:40:25 roland systemd[1]: Starting Preprocess NFS configuration... Sep 01 16:40:25 roland systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Sep 01 16:40:25 roland systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Sep 01 16:40:25 roland systemd[1]: Starting Create Volatile Files and Directories... Sep 01 16:40:25 roland systemd[1]: Starting Raise network interfaces... Sep 01 16:40:25 roland systemd[1]: Starting Load/Save RF Kill Switch Status... Sep 01 16:40:26 roland systemd[1]: nfs-config.service: Succeeded. Sep 01 16:40:26 roland systemd[1]: Started Preprocess NFS configuration. Sep 01 16:40:26 roland systemd[1]: plymouth-read-write.service: Succeeded. Sep 01 16:40:26 roland systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Sep 01 16:40:26 roland systemd[1]: Received SIGRTMIN+20 from PID 175 (plymouthd). Sep 01 16:40:26 roland systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Sep 01 16:40:26 roland systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Sep 01 16:40:26 roland systemd[1]: Reached target NFS client services. Sep 01 16:40:26 roland systemd[1]: Started Load/Save RF Kill Switch Status. Sep 01 16:40:26 roland systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Sep 01 16:40:26 roland systemd[1]: Started Create Volatile Files and Directories. Sep 01 16:40:26 roland systemd[1]: Starting RPC bind portmap service... Sep 01 16:40:26 roland systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Sep 01 16:40:26 roland systemd[1]: Starting Update UTMP about System Boot/Shutdown... Sep 01 16:40:26 roland systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Sep 01 16:40:26 roland systemd[1]: Started ifup for wlan0. Sep 01 16:40:26 roland systemd[1]: Started Update UTMP about System Boot/Shutdown. Sep 01 16:40:26 roland systemd[1]: Reached target System Initialization. Sep 01 16:40:26 roland systemd[1]: Listening on D-Bus System Message Bus Socket. Sep 01 16:40:26 roland systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Sep 01 16:40:26 roland systemd[1]: Listening on triggerhappy.socket. Sep 01 16:40:26 roland systemd[1]: Reached target Sockets. Sep 01 16:40:26 roland systemd[1]: Reached target Basic System. Sep 01 16:40:26 roland systemd[1]: Starting Wireless Services... Sep 01 16:40:26 roland systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Sep 01 16:40:26 roland systemd[1]: Started volumio-remote-updater.service. Sep 01 16:40:26 roland kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Sep 01 16:40:26 roland systemd[1]: Started UPnP Renderer front-end to MPD. Sep 01 16:40:26 roland systemd[1]: Started Volumio Iptables Module. Sep 01 16:40:26 roland systemd[1]: Starting dhcpcd on all interfaces... Sep 01 16:40:26 roland systemd[1]: Starting Configure Bluetooth Modems connected by UART... Sep 01 16:40:26 roland systemd[1]: Started D-Bus System Message Bus. Sep 01 16:40:26 roland dhcpcd[521]: Not running dhcpcd because /etc/network/interfaces Sep 01 16:40:26 roland dhcpcd[521]: defines some interfaces that will use a Sep 01 16:40:26 roland dhcpcd[521]: DHCP client or static address Sep 01 16:40:26 roland systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Sep 01 16:40:26 roland systemd[1]: Started Manage Sound Card State (restore and store). Sep 01 16:40:26 roland systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Sep 01 16:40:26 roland systemd[1]: Started Volumio Log Rotation Service. Sep 01 16:40:26 roland alsactl[528]: alsactl 1.1.8 daemon started Sep 01 16:40:26 roland systemd[1]: Started Daily Cleanup of Temporary Directories. Sep 01 16:40:26 roland systemd[1]: Started Daily apt download activities. Sep 01 16:40:26 roland systemd[1]: Started Daily apt upgrade and clean activities. Sep 01 16:40:26 roland systemd[1]: Reached target Timers. Sep 01 16:40:26 roland systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Sep 01 16:40:26 roland systemd[1]: Starting WPA supplicant... Sep 01 16:40:26 roland systemd[1]: Starting triggerhappy global hotkey daemon... Sep 01 16:40:26 roland systemd[1]: Starting Login Service... Sep 01 16:40:26 roland systemd[1]: Starting Save/Restore Sound Card State... Sep 01 16:40:26 roland systemd[1]: Started RPC bind portmap service. Sep 01 16:40:26 roland systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Sep 01 16:40:26 roland systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Sep 01 16:40:26 roland systemd[1]: Failed to start dhcpcd on all interfaces. Sep 01 16:40:26 roland systemd[1]: Reached target Remote File Systems (Pre). Sep 01 16:40:26 roland systemd[1]: Reached target Remote File Systems. Sep 01 16:40:26 roland systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Sep 01 16:40:26 roland systemd[1]: Reached target RPC Port Mapper. Sep 01 16:40:27 roland thd[536]: Unable to parse trigger line: Sep 01 16:40:27 roland thd[536]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Sep 01 16:40:27 roland thd[536]: Unable to parse trigger line: Sep 01 16:40:27 roland thd[536]: Unable to parse trigger line: Sep 01 16:40:27 roland thd[536]: Unable to parse trigger line: Sep 01 16:40:27 roland thd[536]: Unable to parse trigger line: Sep 01 16:40:27 roland thd[536]: Unable to parse trigger line: Sep 01 16:40:27 roland thd[536]: Unable to parse trigger line: Sep 01 16:40:27 roland thd[536]: Found socket passed from systemd Sep 01 16:40:27 roland systemd[1]: Started triggerhappy global hotkey daemon. Sep 01 16:40:27 roland systemd-logind[538]: New seat seat0. Sep 01 16:40:27 roland avahi-daemon[529]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Sep 01 16:40:27 roland avahi-daemon[529]: Successfully dropped root privileges. Sep 01 16:40:27 roland avahi-daemon[529]: avahi-daemon 0.7 starting up. Sep 01 16:40:27 roland systemd[1]: hciuart.service: Succeeded. Sep 01 16:40:27 roland systemd[1]: Started Configure Bluetooth Modems connected by UART. Sep 01 16:40:27 roland systemd[1]: Started Save/Restore Sound Card State. Sep 01 16:40:27 roland avahi-daemon[529]: Successfully called chroot(). Sep 01 16:40:27 roland avahi-daemon[529]: Successfully dropped remaining capabilities. Sep 01 16:40:27 roland wpa_supplicant[533]: Successfully initialized wpa_supplicant Sep 01 16:40:27 roland avahi-daemon[529]: Loading service file /services/volumio.service. Sep 01 16:40:27 roland avahi-daemon[529]: Network interface enumeration completed. Sep 01 16:40:27 roland avahi-daemon[529]: Server startup complete. Host name is roland.local. Local service cookie is 2064275824. Sep 01 16:40:27 roland avahi-daemon[529]: Service "Roland" (/services/volumio.service) successfully established. Sep 01 16:40:27 roland sh[491]: wlan0=wlan0 Sep 01 16:40:27 roland systemd[1]: Started Raise network interfaces. Sep 01 16:40:28 roland systemd[1]: Started Login Service. Sep 01 16:40:28 roland systemd[1]: Started Avahi mDNS/DNS-SD Stack. Sep 01 16:40:28 roland systemd[1]: Started WPA supplicant. Sep 01 16:40:28 roland systemd[1]: Reached target Network. Sep 01 16:40:28 roland systemd[1]: Starting Permit User Sessions... Sep 01 16:40:28 roland systemd[1]: Starting Network Time Service... Sep 01 16:40:28 roland systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Sep 01 16:40:28 roland systemd[1]: Reached target Network is Online. Sep 01 16:40:28 roland systemd[1]: Starting /etc/rc.local Compatibility... Sep 01 16:40:28 roland systemd[1]: Starting LSB: Brings up/down network automatically... Sep 01 16:40:28 roland systemd[1]: Starting Samba NMB Daemon... Sep 01 16:40:28 roland systemd[1]: Reached target Sound Card. Sep 01 16:40:28 roland systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 16:40:28 roland systemd[1]: Starting Raspberry Pi bluetooth helper... Sep 01 16:40:28 roland systemd[1]: Started Permit User Sessions. Sep 01 16:40:28 roland systemd[1]: Started /etc/rc.local Compatibility. Sep 01 16:40:28 roland systemd[1]: Starting Hold until boot process finishes up... Sep 01 16:40:28 roland systemd[1]: Starting Terminate Plymouth Boot Screen... Sep 01 16:40:28 roland bthelper[625]: Raspberry Pi BDADDR already set Sep 01 16:40:28 roland systemd[1]: Started Raspberry Pi bluetooth helper. Sep 01 16:40:28 roland volumio-remote-updater[516]: Error: No active session Sep 01 16:40:28 roland volumio-remote-updater[516]: [2024-09-01 16:40:28] [info] asio async_connect error: system:111 (Connection refused) Sep 01 16:40:28 roland volumio-remote-updater[516]: [2024-09-01 16:40:28] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Sep 01 16:40:28 roland volumio-remote-updater[516]: [2024-09-01 16:40:28] [error] handle_connect error: Underlying Transport Error Sep 01 16:40:28 roland loadcpufreq[555]: Loading cpufreq kernel modules...done (none). Sep 01 16:40:28 roland systemd[1]: Starting Bluetooth service... Sep 01 16:40:28 roland systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Sep 01 16:40:28 roland systemd[1]: Received SIGRTMIN+21 from PID 175 (plymouthd). Sep 01 16:40:28 roland systemd[1]: Starting LSB: set CPUFreq kernel parameters... Sep 01 16:40:28 roland volumio[517]: Could not open config: /tmp/upmpdcli.conf Sep 01 16:40:28 roland ifplugd[619]: Network Interface Plugging Daemon...skip eth0...done. Sep 01 16:40:29 roland systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Sep 01 16:40:29 roland systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Sep 01 16:40:29 roland systemd[1]: Started LSB: Brings up/down network automatically. Sep 01 16:40:29 roland systemd[1]: plymouth-quit-wait.service: Succeeded. Sep 01 16:40:29 roland systemd[1]: Started Hold until boot process finishes up. Sep 01 16:40:29 roland systemd[1]: plymouth-quit.service: Succeeded. Sep 01 16:40:29 roland systemd[1]: Started Terminate Plymouth Boot Screen. Sep 01 16:40:29 roland systemd[1]: iptables.service: Succeeded. Sep 01 16:40:29 roland systemd[1]: Received SIGRTMIN+21 from PID 175 (n/a). Sep 01 16:40:29 roland systemd[1]: Started Getty on tty1. Sep 01 16:40:29 roland systemd[1]: Reached target Login Prompts. Sep 01 16:40:29 roland ntpd[616]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 01 16:40:29 roland ntpd[616]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Sep 01 16:40:29 roland systemd[1]: Started Network Time Service. Sep 01 16:40:29 roland ntpd[680]: proto: precision = 1.406 usec (-19) Sep 01 16:40:29 roland ntpd[680]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 01 16:40:29 roland ntpd[680]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 01 16:40:29 roland ntpd[680]: Listen and drop on 0 v6wildcard [::]:123 Sep 01 16:40:29 roland ntpd[680]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 01 16:40:29 roland ntpd[680]: Listen normally on 2 lo 127.0.0.1:123 Sep 01 16:40:29 roland ntpd[680]: Listening on routing socket on fd #19 for interface updates Sep 01 16:40:29 roland ntpd[680]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 01 16:40:29 roland ntpd[680]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 01 16:40:29 roland cpufrequtils[672]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Sep 01 16:40:29 roland systemd[1]: Started LSB: set CPUFreq kernel parameters. Sep 01 16:40:29 roland bluetoothd[668]: Bluetooth daemon 5.50 Sep 01 16:40:29 roland bluetoothd[668]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Sep 01 16:40:29 roland systemd[1]: Started Bluetooth service. Sep 01 16:40:29 roland systemd[1]: Reached target Bluetooth. Sep 01 16:40:29 roland bluetoothd[668]: Starting SDP server Sep 01 16:40:29 roland bluetoothd[668]: Excluding (cli) sap Sep 01 16:40:29 roland haveged[490]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Sep 01 16:40:29 roland haveged[490]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Sep 01 16:40:29 roland haveged[490]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99532 Sep 01 16:40:29 roland haveged[490]: haveged: fills: 0, generated: 0 Sep 01 16:40:29 roland kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Sep 01 16:40:29 roland kernel: Bluetooth: BNEP filters: protocol multicast Sep 01 16:40:29 roland kernel: Bluetooth: BNEP socket layer initialized Sep 01 16:40:29 roland dbus-daemon[526]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=668 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Sep 01 16:40:29 roland bluetoothd[668]: Bluetooth management interface 1.22 initialized Sep 01 16:40:29 roland kernel: Bluetooth: MGMT ver 1.22 Sep 01 16:40:29 roland bluetoothd[668]: Failed to set privacy: Rejected (0x0b) Sep 01 16:40:29 roland systemd[1]: Starting Hostname Service... Sep 01 16:40:30 roland dbus-daemon[526]: [system] Successfully activated service 'org.freedesktop.hostname1' Sep 01 16:40:30 roland systemd[1]: Started Hostname Service. Sep 01 16:40:30 roland ntpd[680]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 01 16:40:30 roland nmbd[631]: [2024/09/01 16:40:30.378394, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Sep 01 16:40:30 roland nmbd[631]: started asyncdns process 699 Sep 01 16:40:30 roland nmbd[631]: [2024/09/01 16:40:30.381129, 0] ../lib/util/become_daemon.c:149(daemon_status) Sep 01 16:40:30 roland nmbd[631]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Sep 01 16:40:30 roland nmbd[631]: [2024/09/01 16:40:30.381324, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Sep 01 16:40:30 roland nmbd[631]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Sep 01 16:40:30 roland wireless.js[507]: Cleaning previous... Sep 01 16:40:31 roland systemd[1]: systemd-rfkill.service: Succeeded. Sep 01 16:40:31 roland sudo[707]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Sep 01 16:40:31 roland sudo[707]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:31 roland sudo[707]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:31 roland sudo[709]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Sep 01 16:40:31 roland sudo[709]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:31 roland ntpd[680]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Sep 01 16:40:31 roland sudo[709]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:31 roland wireless.js[507]: Stopped aP Sep 01 16:40:31 roland sudo[716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 01 16:40:31 roland sudo[716]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:31 roland sudo[716]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:31 roland kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Sep 01 16:40:31 roland sudo[718]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Sep 01 16:40:31 roland sudo[718]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:31 roland sudo[718]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:31 roland sudo[725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 01 16:40:31 roland sudo[725]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:31 roland sudo[725]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:31 roland sudo[727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Sep 01 16:40:31 roland sudo[727]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:32 roland ntpd[680]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Sep 01 16:40:32 roland sudo[727]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:32 roland wireless.js[507]: SETTING APPROPRIATE REG DOMAIN: DE Sep 01 16:40:32 roland sudo[732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 01 16:40:32 roland sudo[732]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:32 roland sudo[732]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:32 roland sudo[734]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Sep 01 16:40:32 roland sudo[734]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:32 roland sudo[734]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:32 roland wireless.js[507]: SUCCESSFULLY SET NEW REGDOMAIN: DE Sep 01 16:40:32 roland wireless.js[507]: Start wireless flow Sep 01 16:40:32 roland wireless.js[507]: Stopped hotspot (if there).. Sep 01 16:40:32 roland sudo[739]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Sep 01 16:40:32 roland sudo[739]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:32 roland sudo[739]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:32 roland sudo[741]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Sep 01 16:40:32 roland sudo[741]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:33 roland ntpd[680]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 01 16:40:33 roland sudo[741]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:33 roland wireless.js[507]: DHCP IP Sep 01 16:40:33 roland wireless.js[507]: Start ap Sep 01 16:40:33 roland wpa_supplicant[743]: Successfully initialized wpa_supplicant Sep 01 16:40:33 roland sudo[744]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Sep 01 16:40:33 roland sudo[744]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:33 roland kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Sep 01 16:40:33 roland dhcpcd[745]: dev: loaded udev Sep 01 16:40:33 roland kernel: 8021q: 802.1Q VLAN Support v1.8 Sep 01 16:40:33 roland dhcpcd-run-hooks[754]: wlan0: starting wpa_supplicant Sep 01 16:40:33 roland dhcpcd-run-hooks[760]: wlan0: failed to start wpa_supplicant Sep 01 16:40:33 roland dhcpcd-run-hooks[761]: 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 Sep 01 16:40:33 roland dhcpcd[745]: wlan0: connected to Access Point `' Sep 01 16:40:33 roland bthelper[625]: Changing power off succeeded Sep 01 16:40:33 roland dhcpcd[745]: no interfaces have a carrier Sep 01 16:40:33 roland dhcpcd[745]: forked to background, child pid 775 Sep 01 16:40:33 roland dhcpcd[775]: wlan0: waiting for carrier Sep 01 16:40:33 roland sudo[744]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:33 roland volumio-remote-updater[516]: [2024-09-01 16:40:33] [info] asio async_connect error: system:111 (Connection refused) Sep 01 16:40:33 roland volumio-remote-updater[516]: [2024-09-01 16:40:33] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Sep 01 16:40:33 roland volumio-remote-updater[516]: [2024-09-01 16:40:33] [error] handle_connect error: Underlying Transport Error Sep 01 16:40:33 roland bthelper[625]: [CHG] Controller D8:3A:DD:98:72:1D Class: 0x0000041c Sep 01 16:40:33 roland bthelper[625]: Changing power on succeeded Sep 01 16:40:34 roland wpa_supplicant[758]: wlan0: Trying to associate with SSID 'WLAN_Mond' Sep 01 16:40:34 roland wireless.js[507]: trying... Sep 01 16:40:34 roland sudo[783]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 01 16:40:34 roland sudo[783]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:34 roland sudo[783]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:34 roland dhcpcd[775]: wlan0: carrier acquired Sep 01 16:40:34 roland dhcpcd[775]: wlan0: connected to Access Point `WLAN_Mond' Sep 01 16:40:34 roland wpa_supplicant[758]: wlan0: Associated with 3c:a6:2f:4b:ab:90 Sep 01 16:40:34 roland wpa_supplicant[758]: wlan0: CTRL-EVENT-CONNECTED - Connection to 3c:a6:2f:4b:ab:90 completed [id=0 id_str=] Sep 01 16:40:34 roland wpa_supplicant[758]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Sep 01 16:40:34 roland wpa_supplicant[758]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Sep 01 16:40:34 roland dhcpcd[775]: DUID 00:01:00:01:2d:f2:1e:52:d8:3a:dd:98:72:1c Sep 01 16:40:34 roland dhcpcd[775]: wlan0: IAID dd:98:72:1c Sep 01 16:40:34 roland dhcpcd[775]: wlan0: adding address fe80::3b29:fc86:f15d:5fcc Sep 01 16:40:34 roland dhcpcd[775]: ipv6_addaddr1: Permission denied Sep 01 16:40:34 roland dhcpcd[775]: wlan0: carrier lost Sep 01 16:40:34 roland dhcpcd[775]: wlan0: carrier acquired Sep 01 16:40:34 roland dhcpcd[775]: wlan0: IAID dd:98:72:1c Sep 01 16:40:34 roland dhcpcd[775]: wlan0: soliciting an IPv6 router Sep 01 16:40:35 roland wireless.js[507]: trying... Sep 01 16:40:35 roland sudo[798]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 01 16:40:35 roland sudo[798]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:35 roland sudo[798]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:35 roland dhcpcd[775]: wlan0: soliciting a DHCP lease Sep 01 16:40:35 roland dhcpcd[775]: wlan0: offered 192.168.178.74 from 192.168.178.1 Sep 01 16:40:35 roland dhcpcd[775]: wlan0: probing address 192.168.178.74/24 Sep 01 16:40:36 roland wireless.js[507]: trying... Sep 01 16:40:36 roland sudo[801]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 01 16:40:36 roland sudo[801]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:36 roland sudo[801]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:37 roland wireless.js[507]: trying... Sep 01 16:40:37 roland sudo[804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 01 16:40:37 roland sudo[804]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:37 roland sudo[804]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:38 roland wireless.js[507]: trying... Sep 01 16:40:38 roland sudo[807]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 01 16:40:38 roland sudo[807]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:38 roland sudo[807]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:39 roland wireless.js[507]: trying... Sep 01 16:40:39 roland sudo[810]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 01 16:40:39 roland sudo[810]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:39 roland sudo[810]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:40 roland wireless.js[507]: trying... Sep 01 16:40:40 roland sudo[813]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 01 16:40:40 roland sudo[813]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:40 roland sudo[813]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:40 roland dhcpcd[775]: wlan0: leased 192.168.178.74 for 864000 seconds Sep 01 16:40:40 roland avahi-daemon[529]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.178.74. Sep 01 16:40:40 roland dhcpcd[775]: wlan0: adding route to 192.168.178.0/24 Sep 01 16:40:40 roland dhcpcd[775]: wlan0: adding default route via 192.168.178.1 Sep 01 16:40:40 roland avahi-daemon[529]: New relevant interface wlan0.IPv4 for mDNS. Sep 01 16:40:40 roland avahi-daemon[529]: Registering new address record for 192.168.178.74 on wlan0.IPv4. Sep 01 16:40:41 roland wireless.js[507]: trying... Sep 01 16:40:41 roland sudo[837]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 01 16:40:41 roland sudo[837]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:41 roland sudo[837]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:41 roland wireless.js[507]: Connected to: ----WLAN_Mond Sep 01 16:40:41 roland wireless.js[507]: ---- Sep 01 16:40:41 roland sudo[840]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 16:40:41 roland sudo[840]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:41 roland volumio-remote-updater[516]: [2024-09-01 16:40:41] [info] asio async_connect error: system:111 (Connection refused) Sep 01 16:40:41 roland volumio-remote-updater[516]: [2024-09-01 16:40:41] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Sep 01 16:40:41 roland volumio-remote-updater[516]: [2024-09-01 16:40:41] [error] handle_connect error: Underlying Transport Error Sep 01 16:40:41 roland sudo[840]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:41 roland wireless.js[507]: ... joined AP, wlan0 IPv4 is 192.168.178.74, ipV6 is undefined Sep 01 16:40:41 roland wireless.js[507]: It's done! AP Sep 01 16:40:41 roland systemd[1]: Started Wireless Services. Sep 01 16:40:41 roland kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Sep 01 16:40:41 roland systemd[1]: Started Volumio Backend Module. Sep 01 16:40:41 roland systemd[1]: Started Volumio Cpu Tweaker. Sep 01 16:40:41 roland volumio-cpu-tweak[846]: Setting RT Priority for mpd Sep 01 16:40:41 roland volumio-cpu-tweak[846]: pid 35's current scheduling policy: SCHED_OTHER Sep 01 16:40:41 roland volumio-cpu-tweak[846]: pid 35's current scheduling priority: 0 Sep 01 16:40:41 roland volumio-cpu-tweak[846]: Setting MPD Affinity Sep 01 16:40:41 roland volumio-cpu-tweak[846]: pid 3's current affinity mask: f Sep 01 16:40:41 roland volumio-cpu-tweak[846]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Sep 01 16:40:41 roland volumio-cpu-tweak[846]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Sep 01 16:40:41 roland systemd[1]: volumio_cpu_tweak.service: Succeeded. Sep 01 16:40:42 roland ntpd[680]: Listen normally on 3 wlan0 192.168.178.74:123 Sep 01 16:40:42 roland ntpd[680]: new interface(s) found: waking up resolver Sep 01 16:40:44 roland volumio[845]: info: ------------------------------------------- Sep 01 16:40:44 roland volumio[845]: info: ----- Volumio3 ---- Sep 01 16:40:44 roland volumio[845]: info: ------------------------------------------- Sep 01 16:40:44 roland volumio[845]: info: ----- System startup ---- Sep 01 16:40:44 roland volumio[845]: info: ------------------------------------------- Sep 01 16:40:45 roland nmbd[631]: [2024/09/01 16:40:45.390271, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 01 16:40:45 roland nmbd[631]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Sep 01 16:40:45 roland systemd[1]: Started Samba NMB Daemon. Sep 01 16:40:45 roland systemd[1]: Starting Samba Winbind Daemon... Sep 01 16:40:45 roland winbindd[870]: [2024/09/01 16:40:45.867367, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Sep 01 16:40:45 roland winbindd[870]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Sep 01 16:40:45 roland systemd[1]: Started Samba Winbind Daemon. Sep 01 16:40:45 roland winbindd[870]: [2024/09/01 16:40:45.903225, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 01 16:40:45 roland winbindd[870]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Sep 01 16:40:45 roland systemd[1]: Starting Samba SMB Daemon... Sep 01 16:40:46 roland volumio[845]: info: MYVOLUMIO Environment detected Sep 01 16:40:46 roland smbd[875]: [2024/09/01 16:40:46.630908, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 01 16:40:46 roland systemd[1]: Started Samba SMB Daemon. Sep 01 16:40:46 roland smbd[875]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Sep 01 16:40:46 roland systemd[1]: Reached target Multi-User System. Sep 01 16:40:46 roland systemd[1]: Reached target Graphical Interface. Sep 01 16:40:46 roland volumio[845]: info: Plugin folders cleanup Sep 01 16:40:46 roland volumio[845]: info: Scanning into folder /volumio/app/plugins/ Sep 01 16:40:46 roland volumio[845]: info: Scanning category audio_interface Sep 01 16:40:46 roland volumio[845]: info: Scanning category miscellanea Sep 01 16:40:46 roland systemd[1]: Starting Update UTMP about System Runlevel Changes... Sep 01 16:40:46 roland volumio[845]: info: Scanning category music_service Sep 01 16:40:46 roland volumio[845]: info: Scanning category plugins.json Sep 01 16:40:46 roland volumio[845]: info: Scanning category system_controller Sep 01 16:40:46 roland volumio[845]: info: Scanning category user_interface Sep 01 16:40:46 roland volumio[845]: info: Scanning into folder /data/plugins/ Sep 01 16:40:46 roland volumio[845]: info: Scanning category music_service Sep 01 16:40:46 roland volumio[845]: info: Scanning category system_hardware Sep 01 16:40:46 roland volumio[845]: info: Plugin folders cleanup completed Sep 01 16:40:46 roland volumio[845]: info: ------------------------------------------- Sep 01 16:40:46 roland volumio[845]: info: ----- Core plugins startup ---- Sep 01 16:40:46 roland volumio[845]: info: ------------------------------------------- Sep 01 16:40:46 roland volumio[845]: info: Loading plugins from folder /volumio/app/plugins/ Sep 01 16:40:46 roland volumio[845]: info: Adding plugin upnp to MyMusic Plugins Sep 01 16:40:46 roland volumio[845]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 01 16:40:46 roland volumio[845]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 01 16:40:46 roland volumio[845]: info: Loading plugins from folder /data/plugins/ Sep 01 16:40:46 roland volumio[845]: info: Loading plugin "system"... Sep 01 16:40:46 roland systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Sep 01 16:40:46 roland systemd[1]: Started Update UTMP about System Runlevel Changes. Sep 01 16:40:46 roland systemd[1]: Startup finished in 17.006s (kernel) + 26.834s (userspace) = 43.840s. Sep 01 16:40:46 roland volumio[845]: info: Loading plugin "appearance"... Sep 01 16:40:48 roland volumio[845]: info: Loading plugin "network"... Sep 01 16:40:48 roland volumio[845]: info: Refreshing Cached IP Addresses Sep 01 16:40:48 roland sudo[890]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 16:40:48 roland sudo[890]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:48 roland volumio[845]: info: Loading plugin "services"... Sep 01 16:40:48 roland sudo[892]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 16:40:48 roland sudo[892]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:48 roland volumio[845]: info: Loading plugin "alsa_controller"... Sep 01 16:40:48 roland sudo[892]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:48 roland sudo[895]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 16:40:48 roland sudo[895]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:48 roland sudo[890]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:48 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 16:40:48 roland volumio[845]: info: Loading plugin "wizard"... Sep 01 16:40:48 roland volumio[845]: info: Loading plugin "networkfs"... Sep 01 16:40:48 roland volumio[845]: info: Starting Udev Watcher for removable devices Sep 01 16:40:48 roland sudo[903]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=media,password=PW-unterhaltung,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.75/music /mnt/NAS/NAS_Music Sep 01 16:40:48 roland sudo[903]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:40:48 roland volumio[845]: info: Ignoring mount for partition: boot Sep 01 16:40:48 roland volumio[845]: info: Ignoring mount for partition: volumio Sep 01 16:40:48 roland volumio[845]: info: Ignoring mount for partition: volumio_data Sep 01 16:40:48 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 16:40:48 roland volumio[845]: info: Loading plugin "volumio_command_line_client"... Sep 01 16:40:48 roland volumio[845]: info: Loading plugin "upnp"... Sep 01 16:40:48 roland volumio[845]: info: [1725201648948] Starting Upmpd Daemon Sep 01 16:40:48 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 16:40:48 roland volumio[845]: info: Loading plugin "my_music"... Sep 01 16:40:48 roland volumio[845]: info: Loading plugin "mpd"... Sep 01 16:40:49 roland kernel: Key type cifs.spnego registered Sep 01 16:40:49 roland kernel: Key type cifs.idmap registered Sep 01 16:40:49 roland 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. Sep 01 16:40:49 roland kernel: CIFS: Attempting to mount \\192.168.178.75\music Sep 01 16:40:49 roland kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Sep 01 16:40:49 roland kernel: CIFS: VFS: \\192.168.178.75 Send error in SessSetup = -13 Sep 01 16:40:49 roland kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Sep 01 16:40:49 roland sudo[903]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:49 roland sudo[895]: pam_unix(sudo:session): session closed for user root Sep 01 16:40:49 roland volumio[845]: info: Loading plugin "upnp_browser"... Sep 01 16:40:50 roland volumio[845]: info: Loading plugin "alarm-clock"... Sep 01 16:40:50 roland volumio[845]: info: Loading plugin "airplay_emulation"... Sep 01 16:40:50 roland volumio[845]: info: Starting Shairport Sync Sep 01 16:40:50 roland volumio[845]: info: Loading plugin "last_100"... Sep 01 16:40:50 roland volumio[845]: info: Loading plugin "webradio"... Sep 01 16:40:50 roland volumio[845]: info: Loading plugin "i2s_dacs"... Sep 01 16:40:50 roland volumio[845]: info: Loading plugin "volumiodiscovery"... Sep 01 16:40:50 roland volumio[845]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 16:40:50 roland volumio[845]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 16:40:50 roland volumio[845]: *** WARNING *** For more information see Sep 01 16:40:50 roland volumio[845]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 16:40:50 roland node[845]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 16:40:50 roland volumio[845]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 16:40:50 roland volumio[845]: *** WARNING *** For more information see Sep 01 16:40:50 roland node[845]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 16:40:50 roland node[845]: *** WARNING *** For more information see Sep 01 16:40:50 roland node[845]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 16:40:50 roland node[845]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 16:40:50 roland node[845]: *** WARNING *** For more information see Sep 01 16:40:50 roland volumio[845]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 01 16:40:50 roland volumio[845]: info: Discovery: Started advertising with name: Roland Sep 01 16:40:50 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 16:40:50 roland volumio[845]: info: Loading plugin "spop"... Sep 01 16:40:51 roland volumio-remote-updater[516]: [2024-09-01 16:40:51] [connect] Successful connection Sep 01 16:40:52 roland volumio[845]: info: Loading plugin "youtube2"... Sep 01 16:40:54 roland volumio[845]: info: Loading plugin "ytcr"... Sep 01 16:40:55 roland systemd[1]: systemd-fsckd.service: Succeeded. Sep 01 16:40:58 roland volumio[845]: info: Loading plugin "ytmusic"... Sep 01 16:41:00 roland systemd[1]: systemd-hostnamed.service: Succeeded. Sep 01 16:41:00 roland volumio[845]: info: Loading plugin "gpio-buttons"... Sep 01 16:41:01 roland volumio[845]: info: GPIO-Buttons initialized Sep 01 16:41:01 roland volumio[845]: info: Loading plugin "outputs"... Sep 01 16:41:01 roland volumio[845]: info: Loading plugin "albumart"... Sep 01 16:41:01 roland volumio[845]: info: Plugin example_plugin is not enabled Sep 01 16:41:01 roland volumio[845]: info: Loading plugin "inputs"... Sep 01 16:41:01 roland volumio[845]: info: Loading plugin "updater_comm"... Sep 01 16:41:01 roland volumio[845]: info: Plugin mpdemulation is not enabled Sep 01 16:41:01 roland volumio[845]: info: Loading plugin "rest_api"... Sep 01 16:41:01 roland volumio[845]: info: Loading plugin "websocket"... Sep 01 16:41:01 roland volumio[845]: info: Starting Socket.io Server version 2.3.0 Sep 01 16:41:01 roland volumio[845]: info: Loading i18n strings for locale de Sep 01 16:41:01 roland volumio[845]: Updating browse sources language Sep 01 16:41:01 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 16:41:01 roland volumio[845]: Forking 3 albumart workers Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::initPlayerControls Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 16:41:02 roland volumio[845]: Express server listening on port 3000 Sep 01 16:41:02 roland volumio[845]: [Metrics] WebUI: 18s 472.74ms Sep 01 16:41:02 roland volumio[845]: info: CoreStateMachine::resetVolumioState Sep 01 16:41:02 roland volumio[845]: info: CoreStateMachine::getcurrentVolume Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 16:41:02 roland volumio[845]: info: Cannot read play queue from file Sep 01 16:41:02 roland sudo[971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 16:41:02 roland sudo[971]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:02 roland sudo[973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 16:41:02 roland sudo[973]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:02 roland sudo[973]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:02 roland sudo[971]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:02 roland volumio[845]: info: Cannot mount NAS NAS_Music at system boot, trial number 1 ,retrying in 5 seconds Sep 01 16:41:02 roland volumio[845]: verbose: New Socket.io Connection to 192.168.178.74:3000 from 192.168.178.27 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Sep 01 16:41:02 roland volumio[845]: verbose: New Socket.io Connection to 192.168.178.74:3000 from 192.168.178.27 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 01 16:41:02 roland volumio[845]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Sep 01 16:41:02 roland volumio[845]: info: CoreStateMachine::pushState Sep 01 16:41:02 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::volumioPushState Sep 01 16:41:02 roland volumio[845]: info: CoreStateMachine::updateTrackBlock Sep 01 16:41:02 roland volumio[845]: info: CorePlayQueue::getTrackBlock Sep 01 16:41:02 roland volumio[845]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 16:41:03 roland volumio[845]: Starting albumart workers Sep 01 16:41:03 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 16:41:03 roland volumio[845]: Starting albumart workers Sep 01 16:41:03 roland volumio[845]: Starting albumart workers Sep 01 16:41:03 roland volumio[845]: info: CoreStateMachine::setRepeat null single undefined Sep 01 16:41:03 roland volumio[845]: info: CoreStateMachine::pushState Sep 01 16:41:03 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:03 roland volumio[845]: info: CoreCommandRouter::volumioPushState Sep 01 16:41:03 roland volumio[845]: info: CoreStateMachine::setRandom null Sep 01 16:41:03 roland volumio[845]: info: CoreStateMachine::pushState Sep 01 16:41:03 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:03 roland volumio[845]: info: CoreCommandRouter::volumioPushState Sep 01 16:41:03 roland volumio[845]: info: Setting Device type: Raspberry PI Sep 01 16:41:03 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Sep 01 16:41:03 roland volumio[845]: info: Completed loading Core Plugins Sep 01 16:41:03 roland volumio[845]: info: Preparing to generate the ALSA configuration file Sep 01 16:41:03 roland volumio[845]: info: CoreStateMachine::pushState Sep 01 16:41:03 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:03 roland volumio[845]: info: CoreCommandRouter::volumioPushState Sep 01 16:41:03 roland volumio[845]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Sep 01 16:41:03 roland volumio[845]: info: USB Boot Capable - System SBC Revision found in cpuinfo: 902120 Sep 01 16:41:03 roland volumio[845]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Sep 01 16:41:03 roland volumio[845]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 01 16:41:03 roland volumio[845]: info: Reading ALSA contributions from plugins. Sep 01 16:41:03 roland sudo[991]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 16:41:03 roland sudo[991]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:03 roland systemd[1]: Started UPnP Renderer front-end to MPD. Sep 01 16:41:03 roland sudo[991]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:04 roland volumio[845]: info: Discovery: adding f823e73f-baa3-4125-876e-ef3b4b857690 Sep 01 16:41:04 roland volumio[845]: info: Discovery: Found device Roland Sep 01 16:41:04 roland sudo[996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 16:41:04 roland sudo[996]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::volumioGetState Sep 01 16:41:04 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:04 roland volumio[845]: info: Discovery: adding 60df01ac-863f-4f9e-ab8d-a83d8693079a Sep 01 16:41:04 roland sudo[1001]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 16:41:04 roland sudo[1001]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:04 roland volumio[845]: info: Discovery: Found device Hobbyraum Sep 01 16:41:04 roland sudo[1001]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:04 roland sudo[996]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:04 roland volumio[845]: info: Discovery: Connecting to remote: 192.168.178.27 Sep 01 16:41:04 roland volumio[845]: info: Upmpdcli Daemon Started Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::volumioGetState Sep 01 16:41:04 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:04 roland volumio[845]: info: Discovery: Connected to remote: 192.168.178.27 Sep 01 16:41:04 roland volumio[845]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Sep 01 16:41:04 roland volumio[845]: verbose: New Socket.io Connection to 192.168.178.74 from 192.168.178.70 UA: Mozilla/5.0 (X11; Linux x86_64; rv:129.0) Gecko/20100101 Firefox/129.0 Engine version: 3 Transport: polling Total Clients: 4 Sep 01 16:41:04 roland volumio[845]: info: Asound.conf file unchanged, so no further update is needed Sep 01 16:41:04 roland volumio[845]: info: Output device has changed, restarting MPD Sep 01 16:41:04 roland sudo[1027]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 16:41:04 roland sudo[1027]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:04 roland volumio[845]: info: Output device has changed, restarting Shairport Sync Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 16:41:04 roland sudo[1027]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:04 roland sudo[1029]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 16:41:04 roland sudo[1029]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:04 roland volumio[845]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 16:41:04 roland volumio[845]: info: ___________ START PLUGINS ___________ Sep 01 16:41:04 roland volumio[845]: info: ControllerMpd::onStart: Initializing MPD Sep 01 16:41:04 roland volumio[845]: info: Creating MPD Configuration file Sep 01 16:41:04 roland systemd[1]: Listening on mpd.socket. Sep 01 16:41:04 roland systemd[1]: Starting Music Player Daemon... Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 16:41:04 roland volumio[845]: info: [1725201664497] CoreMusicLibrary::Adding element Medienserver Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 16:41:04 roland sudo[1037]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 16:41:04 roland sudo[1040]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 16:41:04 roland sudo[1037]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:04 roland sudo[1040]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 16:41:04 roland sudo[1037]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:04 roland systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 01 16:41:04 roland systemd[1]: mpd.service: Succeeded. Sep 01 16:41:04 roland systemd[1]: Stopped Music Player Daemon. Sep 01 16:41:04 roland systemd[1]: Starting Music Player Daemon... Sep 01 16:41:04 roland volumio[845]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 16:41:04 roland volumio[845]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 16:41:04 roland volumio[845]: info: [1725201664667] CoreMusicLibrary::Adding element Last_100 Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 16:41:04 roland volumio[845]: info: [1725201664671] CoreMusicLibrary::Adding element Webradio Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 16:41:04 roland volumio[845]: info: Initializing BBC Radios Sep 01 16:41:04 roland volumio[845]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 16:41:04 roland sudo[1046]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 16:41:04 roland sudo[1046]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:04 roland sudo[1046]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Sep 01 16:41:04 roland sudo[1046]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 16:41:04 roland volumio[845]: info: Creating Spotify config file Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 16:41:04 roland volumio[845]: info: [1725201664935] CoreMusicLibrary::Adding element YouTube2 Sep 01 16:41:04 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 16:41:04 roland volumio[845]: Cannot find translation for source YouTube2 Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 16:41:05 roland volumio[845]: info: [1725201665023] CoreMusicLibrary::Adding element YouTube Music Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 16:41:05 roland volumio[845]: Cannot find translation for source YouTube2 Sep 01 16:41:05 roland volumio[845]: Cannot find translation for source YouTube Music Sep 01 16:41:05 roland volumio[845]: info: GPIO-Buttons: Reading config and creating triggers... Sep 01 16:41:05 roland volumio[845]: info: GPIO-Buttons: playPause on pin 17 Sep 01 16:41:05 roland volumio[845]: info: GPIO-Buttons: volumeUp on pin 27 Sep 01 16:41:05 roland volumio[845]: info: GPIO-Buttons: volumeDown on pin 22 Sep 01 16:41:05 roland volumio[845]: info: GPIO-Buttons: previous on pin 23 Sep 01 16:41:05 roland volumio[845]: info: GPIO-Buttons: next on pin 24 Sep 01 16:41:05 roland volumio[845]: info: GPIO-Buttons: shutdown on pin 3 Sep 01 16:41:05 roland volumio[845]: info: Volumio Calling Home Sep 01 16:41:05 roland volumio[845]: info: GPIO-Buttons started Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::volumioGetState Sep 01 16:41:05 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:05 roland volumio[845]: info: MPD Permissions set Sep 01 16:41:05 roland volumio[845]: info: MPD Permissions set Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::volumioGetVisibleSources Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 16:41:05 roland volumio[845]: info: Listing playlists Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 16:41:05 roland volumio[845]: info: Spotify config file written Sep 01 16:41:05 roland sudo[1106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 01 16:41:05 roland sudo[1106]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:05 roland volumio[845]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Sep 01 16:41:05 roland volumio[845]: info: Volumio called home Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland systemd[1]: Started go-librespot Daemon. Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 16:41:05 roland go-librespot[1109]: Librespot-go daemon starting... Sep 01 16:41:05 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 16:41:05 roland sudo[1106]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:06 roland volumio[845]: info: Starting Shairport Sync Sep 01 16:41:06 roland volumio[845]: info: Starting Shairport Sync Sep 01 16:41:06 roland sudo[1124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 16:41:06 roland volumio-remote-updater[516]: [2024-09-01 16:41:06] [connect] Successful connection Sep 01 16:41:06 roland sudo[1124]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:06 roland volumio[845]: info: Starting Shairport Sync Sep 01 16:41:06 roland sudo[1127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 16:41:06 roland sudo[1127]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:06 roland systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 01 16:41:06 roland systemd[1]: shairport-sync.service: Succeeded. Sep 01 16:41:06 roland systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 01 16:41:06 roland volumio[845]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 16:41:06 roland volumio[845]: SPOTIFY: BQBTpR0icsyWIKznCGlDbbKeEbbStht8RlHrcpp1I2rzhYVPIsetje-1l7TdX5QTqws4mnJsXmGBM_U_Z31YtTBVg_jVgiYyvSikEwYQdSP2ygDgH6fOgWIAvCGoNirFAPW3ox5edwKfyn8iYmJdyUwsIRMU3LIqj-CXbfYoIZe2wcJcdBT2vqX-39d5AC9uzaMxz-TouVvSVlD901PfMEzdb-gPQ7n4NsypzKLh4qH6gQTaIyhS26-oxLkAqRt37qyf2lBI0BiddUw Sep 01 16:41:06 roland volumio[845]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 16:41:06 roland volumio[845]: info: New Spotify access token = BQBTpR0icsyWIKznCGlDbbKeEbbStht8RlHrcpp1I2rzhYVPIsetje-1l7TdX5QTqws4mnJsXmGBM_U_Z31YtTBVg_jVgiYyvSikEwYQdSP2ygDgH6fOgWIAvCGoNirFAPW3ox5edwKfyn8iYmJdyUwsIRMU3LIqj-CXbfYoIZe2wcJcdBT2vqX-39d5AC9uzaMxz-TouVvSVlD901PfMEzdb-gPQ7n4NsypzKLh4qH6gQTaIyhS26-oxLkAqRt37qyf2lBI0BiddUw Sep 01 16:41:06 roland sudo[1130]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 16:41:06 roland sudo[1130]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:06 roland go-librespot[1109]: time="2024-09-01T16:41:06+02:00" level=info msg="generated new device id: 47efdaf47746720d92525c92dd164e18b7d06b85" Sep 01 16:41:06 roland go-librespot[1109]: time="2024-09-01T16:41:06+02:00" level=debug msg="stored credentials found for 5ka1idsxg34hpl7qi69kbkxmr" Sep 01 16:41:06 roland volumio[845]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 01 16:41:06 roland systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 16:41:06 roland volumio[845]: info: CoreCommandRouter::volumioGetState Sep 01 16:41:06 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:06 roland sudo[1124]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:06 roland systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 01 16:41:06 roland systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Sep 01 16:41:06 roland systemd[1]: shairport-sync.service: Succeeded. Sep 01 16:41:06 roland systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 01 16:41:06 roland systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 16:41:06 roland sudo[1127]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:06 roland sudo[1130]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:06 roland volumio[845]: info: Shairport-Sync Started Sep 01 16:41:06 roland volumio[845]: Error adding Membership: Error: addMembership EINVAL Sep 01 16:41:06 roland volumio-remote-updater[516]: [2024-09-01 16:41:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725201666 101 Sep 01 16:41:06 roland volumio[845]: 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 Sep 01 16:41:06 roland volumio[845]: info: Shairport-Sync Started Sep 01 16:41:06 roland volumio[845]: info: Shairport-Sync Started Sep 01 16:41:06 roland volumio[845]: SPOTIFY: User informations: {"display_name":"Roland","external_urls":{"spotify":"https://open.spotify.com/user/5ka1idsxg34hpl7qi69kbkxmr"},"href":"https://api.spotify.com/v1/users/5ka1idsxg34hpl7qi69kbkxmr","id":"5ka1idsxg34hpl7qi69kbkxmr","images":[],"type":"user","uri":"spotify:user:5ka1idsxg34hpl7qi69kbkxmr","followers":{"href":null,"total":0},"country":"DE","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"roland.joerger@gmx.de"} Sep 01 16:41:06 roland volumio[845]: info: Spotify Successfully logged in Sep 01 16:41:06 roland volumio[845]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 16:41:06 roland volumio[845]: info: [1725201666914] CoreMusicLibrary::Adding element Spotify Sep 01 16:41:06 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 16:41:06 roland volumio[845]: Cannot find translation for source YouTube2 Sep 01 16:41:06 roland volumio[845]: Cannot find translation for source YouTube Music Sep 01 16:41:06 roland volumio[845]: Cannot find translation for source Spotify Sep 01 16:41:07 roland go-librespot[1109]: time="2024-09-01T16:41:07+02:00" level=debug msg="obtained new client token: AAB5gqD1mKtDs/Dd6W0qkqGHXgUG0pa56UZrkhglN4hKLfL6JvKe1OgPlPpVor38tN31rLvu5JY3Ku7mKg0ceFNqVTQRvpdHttkSLUUfPgYA4zlki53Z+hdHbXDxbvvFaWDvz/Cvos1VwkdgdJcA68Qc3CJaK0jNp0UHKU/5PJxIPDU+k6wMyFV+l3xDqOiQnTBFdxTVFi6oZagzJnCNYKhfVeZuBJ004KzWZIuKd3S69ccI8lBeBYXXjzeL5cHk" Sep 01 16:41:07 roland go-librespot[1109]: time="2024-09-01T16:41:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 16:41:07 roland go-librespot[1109]: time="2024-09-01T16:41:07+02:00" level=debug msg="completed keyexchange" Sep 01 16:41:07 roland sudo[1140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=media,password=PW-unterhaltung,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.75/music /mnt/NAS/NAS_Music Sep 01 16:41:07 roland sudo[1140]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:07 roland kernel: CIFS: Attempting to mount \\192.168.178.75\music Sep 01 16:41:07 roland sudo[1140]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:07 roland kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Sep 01 16:41:07 roland kernel: CIFS: VFS: \\192.168.178.75 Send error in SessSetup = -13 Sep 01 16:41:07 roland kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Sep 01 16:41:07 roland volumio[845]: info: Cannot mount NAS NAS_Music at system boot, trial number 2 ,retrying in 5 seconds Sep 01 16:41:07 roland volumio[845]: info: [yt-cast-receiver] DIAL server listening on port 8098 Sep 01 16:41:07 roland volumio[845]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 16:41:07 roland volumio[845]: info: CoreCommandRouter::volumioGetState Sep 01 16:41:07 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:07 roland volumio[845]: info: CoreStateMachine::pushState Sep 01 16:41:07 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:07 roland volumio[845]: info: CoreCommandRouter::volumioPushState Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="completed challenge" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="authenticated as 5ka1idsxg34hpl7qi69kbkxmr" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="authenticated as 5ka1idsxg34hpl7qi69kbkxmr" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="dealer connection opened" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="received connection id: NTE1NWZjNjAtNGFiMS00ZDkxLWEzYjItMzM1YmRjYjRmZTdhK2RlYWxlcit0Y3A6Ly8wYWNhNThhYy5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArN0M3RUJFQTc0QjExQ0E4MkNGMjc1N0RGMkVGOERCMjk2Mjc1QkQzNEZGRERFNkUzOEYyM0UyQzRFODI1N0M5Ng==" Sep 01 16:41:08 roland go-librespot[1109]: time="2024-09-01T16:41:08+02:00" level=debug msg="put connect state because NEW_DEVICE" Sep 01 16:41:08 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 16:41:08 roland volumio[845]: info: Received Get System Info Sep 01 16:41:08 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 16:41:08 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 16:41:08 roland volumio[845]: info: Discovery: Getting this device information Sep 01 16:41:08 roland volumio[845]: info: CoreCommandRouter::volumioGetState Sep 01 16:41:08 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:08 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 16:41:09 roland volumio[845]: info: go-librespot daemon successfully initialized Sep 01 16:41:09 roland volumio[845]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Sep 01 16:41:10 roland mpd[1054]: Sep 01 16:41 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 16:41:10 roland systemd[1]: Started Music Player Daemon. Sep 01 16:41:10 roland volumio[845]: Upnp client error: Error: This socket has been ended by the other party Sep 01 16:41:10 roland sudo[1029]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:10 roland sudo[1040]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:10 roland volumio[845]: info: Completed starting Core Plugins Sep 01 16:41:10 roland volumio[845]: info: ------------------------------------------- Sep 01 16:41:10 roland volumio[845]: info: ----- MyVolumio plugins startup ---- Sep 01 16:41:10 roland volumio[845]: info: ------------------------------------------- Sep 01 16:41:10 roland volumio[845]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 01 16:41:11 roland volumio[845]: error: MPD error: The expression evaluated to a falsy value: Sep 01 16:41:11 roland volumio[845]: assert.ok(self.idling) Sep 01 16:41:11 roland volumio[845]: error: The expression evaluated to a falsy value: Sep 01 16:41:11 roland volumio[845]: assert.ok(self.idling) Sep 01 16:41:11 roland volumio[845]: error: updateQueue error: null Sep 01 16:41:11 roland volumio[845]: info: MPD running with PID1054 Sep 01 16:41:11 roland volumio[845]: ,establishing connection Sep 01 16:41:11 roland volumio[845]: error: updateQueue error: null Sep 01 16:41:12 roland volumio[845]: info: Initializing connection to go-librespot Websocket Sep 01 16:41:12 roland go-librespot[1109]: time="2024-09-01T16:41:12+02:00" level=debug msg="new websocket client" Sep 01 16:41:12 roland volumio[845]: info: Connection to go-librespot Websocket established Sep 01 16:41:12 roland sudo[1156]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=media,password=PW-unterhaltung,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.75/music /mnt/NAS/NAS_Music Sep 01 16:41:12 roland sudo[1156]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 16:41:12 roland kernel: CIFS: Attempting to mount \\192.168.178.75\music Sep 01 16:41:12 roland kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Sep 01 16:41:12 roland kernel: CIFS: VFS: \\192.168.178.75 Send error in SessSetup = -13 Sep 01 16:41:12 roland kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Sep 01 16:41:12 roland volumio[845]: info: Cannot mount NAS NAS_Music at system boot, trial number 3 ,retrying in 5 seconds Sep 01 16:41:12 roland sudo[1156]: pam_unix(sudo:session): session closed for user root Sep 01 16:41:12 roland go-librespot[1109]: time="2024-09-01T16:41:12+02:00" level=debug msg="handling transfer player command from 4e42dfdce4fda0e4fe0a5047666f47b02923a4de" Sep 01 16:41:12 roland go-librespot[1109]: time="2024-09-01T16:41:12+02:00" level=trace msg="fetched new page 0 with 10 items (list: 10)" Sep 01 16:41:12 roland go-librespot[1109]: time="2024-09-01T16:41:12+02:00" level=debug msg="loading track spotify:track:4D8Y1kTaD6jjMrmM5C3z7c (paused: false, position: -1525ms)" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=trace msg="emitting websocket event: will_play" Sep 01 16:41:13 roland volumio[845]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4D8Y1kTaD6jjMrmM5C3z7c","play_origin":"playlist"}} Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4D8Y1kTaD6jjMrmM5C3z7c" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=debug msg="requested aes key for file b1e39c7c0e5acc6c703190b84e53368ccd22f8fa, gid: 4D8Y1kTaD6jjMrmM5C3z7c" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=debug msg="fetched first chunk of 20, total size is 10086024 bytes" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=trace msg="seek to -1525ms (diff: -1525ms, samples: -67252, bytes: 0)" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=info msg="loaded track \"Nur der Anfang\" (uri: spotify:track:4D8Y1kTaD6jjMrmM5C3z7c, paused: false, position: -1525ms, duration: 238640ms)" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=debug msg="fetched chunk 3/19, size: 524288" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=trace msg="emitting websocket event: metadata" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=trace msg="emitting websocket event: active" Sep 01 16:41:13 roland go-librespot[1109]: time="2024-09-01T16:41:13+02:00" level=debug msg="sending successful reply for delaer request" Sep 01 16:41:13 roland volumio[845]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4D8Y1kTaD6jjMrmM5C3z7c","name":"Nur der Anfang","artist_names":["Element Of Crime"],"album_name":"Morgens um vier","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028b2b2e45a6d22b80be924f24","position":-1525,"duration":238640,"release_date":"year:2023 month:4 day:6","track_number":4,"disc_number":1}} Sep 01 16:41:13 roland volumio[845]: SPOTIFY: received: {"type":"active","data":null} Sep 01 16:41:13 roland volumio[845]: info: Aligning Spotify Volume to Volumio Volume Sep 01 16:41:13 roland volumio[845]: info: CoreCommandRouter::volumioGetState Sep 01 16:41:13 roland volumio[845]: info: CorePlayQueue::getTrack 0 Sep 01 16:41:13 roland volumio[845]: info: Setting Spotify Volume from Volumio: 3 Sep 01 16:41:14 roland go-librespot[1109]: time="2024-09-01T16:41:14+02:00" level=debug msg="fetched chunk 2/19, size: 524288" Sep 01 16:41:14 roland go-librespot[1109]: time="2024-09-01T16:41:14+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Sep 01 16:41:14 roland go-librespot[1109]: time="2024-09-01T16:41:14+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Sep 01 16:41:14 roland go-librespot[1109]: time="2024-09-01T16:41:14+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 01 16:41:14 roland go-librespot[1109]: time="2024-09-01T16:41:14+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1144" Sep 01 16:41:14 roland go-librespot[1109]: time="2024-09-01T16:41:14+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 01 16:41:14 roland go-librespot[1109]: time="2024-09-01T16:41:14+02:00" level=trace msg="emitting websocket event: playing" Sep 01 16:41:14 roland volumio[845]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4D8Y1kTaD6jjMrmM5C3z7c","play_origin":"playlist"}} Sep 01 16:41:14 roland volumio[845]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 16:41:14 roland volumio[845]: TypeError: Cannot read property 'service' of undefined Sep 01 16:41:14 roland volumio[845]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Sep 01 16:41:14 roland volumio[845]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Sep 01 16:41:14 roland volumio[845]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Sep 01 16:41:14 roland volumio[845]: at WebSocket.emit (events.js:315:20) Sep 01 16:41:14 roland volumio[845]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1209:20) Sep 01 16:41:14 roland volumio[845]: at Receiver.emit (events.js:315:20) Sep 01 16:41:14 roland volumio[845]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:594:14) Sep 01 16:41:14 roland volumio[845]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Sep 01 16:41:14 roland volumio[845]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Sep 01 16:41:14 roland volumio[845]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Sep 01 16:41:14 roland volumio[845]: at writeOrBuffer (internal/streams/writable.js:358:12) Sep 01 16:41:14 roland volumio[845]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Sep 01 16:41:14 roland volumio[845]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1303:35) Sep 01 16:41:14 roland volumio[845]: at Socket.emit (events.js:315:20) Sep 01 16:41:14 roland volumio[845]: at addChunk (internal/streams/readable.js:309:12) Sep 01 16:41:14 roland volumio[845]: at readableAddChunk (internal/streams/readable.js:284:9) Sep 01 16:41:14 roland volumio[845]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 16:41:14 roland go-librespot[1109]: time="2024-09-01T16:41:14+02:00" level=debug msg="fetched chunk 1/19, size: 524288" Sep 01 16:41:14 roland volumio[993]: Generating RSA private key, 4096 bit long modulus (2 primes) Sep 01 16:41:15 roland sudo[1186]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-01 16:40 Sep 01 16:41:15 roland sudo[1186]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"