. Jan 08 00:06:02 main systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Jan 08 00:06:02 main kernel: random: systemd: uninitialized urandom read (16 bytes read) Jan 08 00:06:02 main kernel: random: systemd: uninitialized urandom read (16 bytes read) Jan 08 00:06:02 main kernel: random: systemd: uninitialized urandom read (16 bytes read) Jan 08 00:06:02 main systemd[1]: Listening on Journal Socket. Jan 08 00:06:02 main systemd[1]: Created slice system-systemd\x2dfsck.slice. Jan 08 00:06:02 main systemd[1]: Condition check resulted in Huge Pages File System being skipped. Jan 08 00:06:02 main systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. Jan 08 00:06:02 main systemd[1]: Created slice User and Session Slice. Jan 08 00:06:02 main systemd[1]: Created slice system-getty.slice. Jan 08 00:06:02 main kernel: i2c /dev entries driver Jan 08 00:06:02 main systemd-journald[187]: Journal started Jan 08 00:06:02 main systemd-journald[187]: Runtime journal (/run/log/journal/31189cf30d98866a049b08ee61b75d9e) is 7.5M, max 30.0M, 22.5M free. Feb 14 10:11:59 main systemd-modules-load[189]: Inserted module 'i2c_dev' Jan 08 00:06:02 main fake-hwclock[191]: Sat Jan 8 00:06:02 UTC 2022 Jan 08 00:06:02 main systemd[1]: dynamicswap.service: Succeeded. Jan 08 00:06:02 main systemd[1]: Started Create Static Device Nodes in /dev. Jan 08 00:06:02 main systemd[1]: Starting udev Kernel Device Manager... Jan 08 00:06:02 main systemd[1]: Reached target Local File Systems (Pre). Jan 08 00:06:02 main systemd[1]: Mounting /var/spool/cups... Jan 08 00:06:02 main systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Jan 08 00:06:02 main systemd[1]: Mounting /var/log... Jan 08 00:06:02 main systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Jan 08 00:06:02 main systemd[1]: Mounting /tmp... Jan 08 00:06:02 main systemd[1]: Mounted /var/log. Jan 08 00:06:02 main systemd[1]: Mounted /var/spool/cups. Jan 08 00:06:02 main systemd[1]: Mounted /tmp. Jan 08 00:06:02 main systemd[1]: Mounting /var/spool/cups/tmp... Jan 08 00:06:02 main systemd-udevd[211]: Network interface NamePolicy= disabled on kernel command line, ignoring. Jan 08 00:06:02 main systemd[1]: Starting Flush Journal to Persistent Storage... Jan 08 00:06:02 main systemd[1]: Mounted /var/spool/cups/tmp. Jan 08 00:06:02 main systemd-journald[187]: Runtime journal (/run/log/journal/31189cf30d98866a049b08ee61b75d9e) is 7.5M, max 30.0M, 22.5M free. Jan 08 00:06:02 main systemd[1]: Started udev Kernel Device Manager. Jan 08 00:06:02 main systemd[1]: Started Flush Journal to Persistent Storage. Jan 08 00:06:02 main systemd[1]: Started udev Coldplug all Devices. Jan 08 00:06:02 main systemd[1]: Starting Show Plymouth Boot Screen... Jan 08 00:06:02 main systemd[1]: Starting Helper to synchronize boot up for ifupdown... Jan 08 00:06:02 main systemd[1]: Received SIGRTMIN+20 from PID 247 (plymouthd). Jan 08 00:06:02 main systemd[1]: Started Show Plymouth Boot Screen. Jan 08 00:06:02 main systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jan 08 00:06:02 main systemd[1]: Reached target Local Encrypted Volumes. Jan 08 00:06:02 main systemd[1]: Reached target Paths. Jan 08 00:06:02 main systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Jan 08 00:06:02 main kernel: rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000 Jan 08 00:06:02 main kernel: rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000 Jan 08 00:06:02 main kernel: rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000 Jan 08 00:06:02 main kernel: rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000 Jan 08 00:06:02 main systemd-udevd[230]: Using default interface naming scheme 'v240'. Jan 08 00:06:02 main kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Jan 08 00:06:02 main kernel: mc: Linux media interface: v0.10 Jan 08 00:06:02 main kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Jan 08 00:06:02 main kernel: [vc_sm_connected_init]: start Jan 08 00:06:02 main kernel: [vc_sm_connected_init]: installed successfully Jan 08 00:06:03 main systemd-udevd[240]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jan 08 00:06:03 main systemd-udevd[230]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jan 08 00:06:03 main kernel: videodev: Linux video capture interface: v2.00 Jan 08 00:06:03 main kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Jan 08 00:06:03 main kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Jan 08 00:06:03 main kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Jan 08 00:06:03 main kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Jan 08 00:06:03 main kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Jan 08 00:06:03 main kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Jan 08 00:06:03 main kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Jan 08 00:06:03 main kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Jan 08 00:06:03 main kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Jan 08 00:06:03 main kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jan 08 00:06:03 main kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jan 08 00:06:03 main kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jan 08 00:06:03 main kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jan 08 00:06:03 main kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Jan 08 00:06:03 main kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Jan 08 00:06:03 main kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Jan 08 00:06:03 main kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Jan 08 00:06:03 main kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Jan 08 00:06:03 main kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Jan 08 00:06:03 main kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Jan 08 00:06:03 main kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Jan 08 00:06:03 main kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Jan 08 00:06:03 main kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Jan 08 00:06:03 main kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Jan 08 00:06:04 main kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Jan 08 00:06:04 main kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Jan 08 00:06:04 main kernel: usbcore: registered new interface driver brcmfmac Jan 08 00:06:04 main kernel: brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.txt failed with error -2 Jan 08 00:06:04 main systemd-udevd[224]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jan 08 00:06:04 main systemd[1]: Found device /dev/mmcblk0p1. Jan 08 00:06:04 main kernel: snd_usb_audio: unknown parameter 'nrpacks' ignored Jan 08 00:06:04 main kernel: usbcore: registered new interface driver snd-usb-audio Jan 08 00:06:04 main systemd[1]: Condition check resulted in FUSE Control File System being skipped. Jan 08 00:06:04 main systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Jan 08 00:06:04 main systemd[1]: Condition check resulted in Huge Pages File System being skipped. Jan 08 00:06:04 main systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jan 08 00:06:04 main systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Jan 08 00:06:04 main systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Jan 08 00:06:04 main systemd[1]: Starting File System Check on /dev/mmcblk0p1... Jan 08 00:06:04 main kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Jan 08 00:06:04 main kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Jan 4 2021 19:56:29 version 7.45.229 (617f1f5 CY) FWID 01-2dbd9d2e Jan 08 00:06:04 main systemd[1]: Starting Load/Save RF Kill Switch Status... Jan 08 00:06:04 main systemd-udevd[217]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jan 08 00:06:04 main systemd[1]: Started File System Check Daemon to report status. Jan 08 00:06:04 main systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Jan 08 00:06:04 main systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Jan 08 00:06:04 main systemd[1]: Condition check resulted in Huge Pages File System being skipped. Jan 08 00:06:04 main systemd[1]: Condition check resulted in FUSE Control File System being skipped. Jan 08 00:06:04 main systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jan 08 00:06:04 main systemd-udevd[221]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jan 08 00:06:04 main systemd-udevd[240]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jan 08 00:06:04 main systemd-fsck[367]: fsck.fat 4.1 (2017-01-24) Jan 08 00:06:04 main systemd-fsck[367]: /dev/mmcblk0p1: 336 files, 26666/46774 clusters Jan 08 00:06:04 main systemd-udevd[240]: Using default interface naming scheme 'v240'. Jan 08 00:06:04 main systemd-udevd[240]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jan 08 00:06:04 main systemd[1]: Started Load/Save RF Kill Switch Status. Jan 08 00:06:04 main systemd-udevd[242]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jan 08 00:06:04 main systemd[1]: Started File System Check on /dev/mmcblk0p1. Jan 08 00:06:04 main systemd[1]: Mounting /boot... Jan 08 00:06:04 main systemd-udevd[219]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jan 08 00:06:04 main systemd[1]: Mounted /boot. Jan 08 00:06:04 main systemd[1]: Reached target Local File Systems. Jan 08 00:06:04 main systemd[1]: Starting Create Volatile Files and Directories... Jan 08 00:06:04 main systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Jan 08 00:06:04 main systemd[1]: Starting Preprocess NFS configuration... Jan 08 00:06:04 main systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Jan 08 00:06:05 main systemd-udevd[238]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jan 08 00:06:05 main systemd[1]: Found device /sys/subsystem/net/devices/eth0. Jan 08 00:06:05 main systemd[1]: nfs-config.service: Succeeded. Jan 08 00:06:05 main systemd[1]: Started Preprocess NFS configuration. Jan 08 00:06:05 main systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Jan 08 00:06:05 main systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Jan 08 00:06:05 main systemd[1]: Reached target NFS client services. Jan 08 00:06:05 main systemd[1]: Started ifup for eth0. Jan 08 00:06:05 main systemd[1]: Started Create Volatile Files and Directories. Jan 08 00:06:05 main systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Jan 08 00:06:05 main systemd[1]: Starting Update UTMP about System Boot/Shutdown... Jan 08 00:06:05 main systemd[1]: Starting RPC bind portmap service... Jan 08 00:06:05 main systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Jan 08 00:06:05 main systemd[1]: Started Update UTMP about System Boot/Shutdown. Jan 08 00:06:05 main systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Jan 08 00:06:05 main systemd[1]: Started ifup for wlan0. Jan 08 00:06:05 main systemd[1]: Received SIGRTMIN+20 from PID 247 (plymouthd). Jan 08 00:06:05 main systemd[1]: plymouth-read-write.service: Succeeded. Jan 08 00:06:05 main systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Jan 08 00:06:05 main systemd[1]: Reached target System Initialization. Jan 08 00:06:05 main systemd[1]: Listening on mpd.socket. Jan 08 00:06:05 main systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Jan 08 00:06:05 main systemd[1]: Started Daily Cleanup of Temporary Directories. Jan 08 00:06:05 main systemd[1]: Listening on D-Bus System Message Bus Socket. Jan 08 00:06:05 main systemd[1]: Started Daily man-db regeneration. Jan 08 00:06:05 main systemd[1]: Started Daily apt download activities. Jan 08 00:06:05 main systemd[1]: Started Daily apt upgrade and clean activities. Jan 08 00:06:05 main systemd[1]: Reached target Timers. Jan 08 00:06:05 main systemd[1]: Listening on triggerhappy.socket. Jan 08 00:06:05 main systemd[1]: Reached target Sockets. Jan 08 00:06:05 main systemd[1]: Reached target Basic System. Jan 08 00:06:05 main systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Jan 08 00:06:05 main systemd[1]: Started Manage Sound Card State (restore and store). Jan 08 00:06:05 main systemd[1]: Starting Save/Restore Sound Card State... Jan 08 00:06:05 main systemd[1]: Started UPnP Renderer front-end to MPD. Jan 08 00:06:05 main alsactl[431]: alsactl 1.1.8 daemon started Jan 08 00:06:05 main kernel: 8021q: 802.1Q VLAN Support v1.8 Jan 08 00:06:05 main systemd[1]: Starting triggerhappy global hotkey daemon... Jan 08 00:06:05 main systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Jan 08 00:06:05 main systemd[1]: Starting Configure Bluetooth Modems connected by UART... Jan 08 00:06:05 main systemd[1]: Started Volumio Iptables Module. Jan 08 00:06:05 main systemd[1]: Starting Wireless Services... Jan 08 00:06:05 main thd[438]: Unable to parse trigger line: Jan 08 00:06:05 main thd[438]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Jan 08 00:06:05 main thd[438]: Unable to parse trigger line: Jan 08 00:06:05 main thd[438]: Found socket passed from systemd Jan 08 00:06:05 main thd[438]: Device /dev/input/event5 not suitable. Jan 08 00:06:05 main systemd[1]: Starting Login Service... Jan 08 00:06:05 main systemd[1]: Started D-Bus System Message Bus. Jan 08 00:06:05 main systemd[1]: Starting WPA supplicant... Jan 08 00:06:05 main systemd[1]: Started volumio-remote-updater.service. Jan 08 00:06:05 main systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Jan 08 00:06:05 main systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Jan 08 00:06:05 main systemd[1]: Starting dhcpcd on all interfaces... Jan 08 00:06:05 main systemd[1]: Started RPC bind portmap service. Jan 08 00:06:05 main systemd[1]: Started triggerhappy global hotkey daemon. Jan 08 00:06:05 main systemd[1]: Started Save/Restore Sound Card State. Jan 08 00:06:05 main systemd[1]: Reached target Sound Card. Jan 08 00:06:05 main systemd[1]: Reached target Remote File Systems (Pre). Jan 08 00:06:05 main systemd[1]: Reached target Remote File Systems. Jan 08 00:06:05 main dhcpcd[462]: Not running dhcpcd because /etc/network/interfaces Jan 08 00:06:05 main dhcpcd[462]: defines some interfaces that will use a Jan 08 00:06:05 main dhcpcd[462]: DHCP client or static address Jan 08 00:06:05 main systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Jan 08 00:06:05 main systemd[1]: Reached target RPC Port Mapper. Jan 08 00:06:05 main systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Jan 08 00:06:05 main kernel: uart-pl011 fe201000.serial: no DMA platform data Jan 08 00:06:05 main systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Jan 08 00:06:05 main systemd[1]: Failed to start dhcpcd on all interfaces. Jan 08 00:06:06 main systemd-logind[444]: Watching system buttons on /dev/input/event1 (DaKai 2.4G RX) Jan 08 00:06:06 main systemd-logind[444]: Watching system buttons on /dev/input/event3 (DaKai 2.4G RX System Control) Jan 08 00:06:06 main systemd-logind[444]: Watching system buttons on /dev/input/event4 (DaKai 2.4G RX Consumer Control) Jan 08 00:06:06 main kernel: bcmgenet: Skipping UMAC reset Jan 08 00:06:06 main systemd-logind[444]: New seat seat0. Jan 08 00:06:06 main sh[394]: eth0: waiting for carrier Jan 08 00:06:06 main dhcpcd[416]: eth0: waiting for carrier Jan 08 00:06:06 main kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII Jan 08 00:06:06 main kernel: bcmgenet fd580000.ethernet eth0: Link is Down Jan 08 00:06:06 main avahi-daemon[459]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Jan 08 00:06:06 main avahi-daemon[459]: Successfully dropped root privileges. Jan 08 00:06:06 main avahi-daemon[459]: avahi-daemon 0.7 starting up. Jan 08 00:06:06 main avahi-daemon[459]: Successfully called chroot(). Jan 08 00:06:06 main avahi-daemon[459]: Successfully dropped remaining capabilities. Jan 08 00:06:06 main avahi-daemon[459]: Loading service file /services/volumio.service. Jan 08 00:06:06 main avahi-daemon[459]: Network interface enumeration completed. Jan 08 00:06:06 main kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 08 00:06:06 main avahi-daemon[459]: Server startup complete. Host name is main.local. Local service cookie is 1994370704. Jan 08 00:06:06 main avahi-daemon[459]: Service "Main" (/services/volumio.service) successfully established. Jan 08 00:06:06 main systemd[1]: Started Login Service. Jan 08 00:06:06 main systemd[1]: Started Avahi mDNS/DNS-SD Stack. Jan 08 00:06:06 main sh[410]: wlan0=wlan0 Jan 08 00:06:06 main loadcpufreq[467]: Loading cpufreq kernel modules...done (none). Jan 08 00:06:06 main systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Jan 08 00:06:06 main systemd[1]: Starting LSB: set CPUFreq kernel parameters... Jan 08 00:06:06 main systemd[1]: Started WPA supplicant. Jan 08 00:06:06 main wpa_supplicant[451]: Successfully initialized wpa_supplicant Jan 08 00:06:06 main volumio-remote-updater[454]: Error: No active session Jan 08 00:06:06 main volumio-remote-updater[454]: [2022-01-08 00:06:06] [info] asio async_connect error: system:111 (Connection refused) Jan 08 00:06:06 main volumio-remote-updater[454]: [2022-01-08 00:06:06] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 08 00:06:06 main volumio-remote-updater[454]: [2022-01-08 00:06:06] [error] handle_connect error: Underlying Transport Error Jan 08 00:06:06 main cpufrequtils[529]: CPUFreq Utilities: Setting performance CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Jan 08 00:06:06 main systemd[1]: Started LSB: set CPUFreq kernel parameters. Jan 08 00:06:06 main systemd[1]: iptables.service: Succeeded. Jan 08 00:06:07 main volumio[434]: Could not open config: /tmp/upmpdcli.conf Jan 08 00:06:07 main systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 08 00:06:07 main systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 08 00:06:07 main systemd-udevd[234]: Process '/bin/bash -c '/usr/local/bin/volumio usbattach'' failed with exit code 7. Jan 08 00:06:07 main systemd[1]: Started Helper to synchronize boot up for ifupdown. Jan 08 00:06:07 main systemd[1]: Starting Raise network interfaces... Jan 08 00:06:07 main systemd[1]: Started Raise network interfaces. Jan 08 00:06:07 main systemd[1]: Reached target Network. Jan 08 00:06:07 main systemd[1]: Starting Music Player Daemon... Jan 08 00:06:07 main systemd[1]: Starting Network Time Service... Jan 08 00:06:07 main systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Jan 08 00:06:07 main systemd[1]: Starting Permit User Sessions... Jan 08 00:06:07 main systemd[1]: Reached target Network is Online. Jan 08 00:06:07 main systemd[1]: Starting Samba NMB Daemon... Jan 08 00:06:07 main systemd[1]: Starting /etc/rc.local Compatibility... Jan 08 00:06:07 main systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 08 00:06:07 main systemd[1]: Starting LSB: Brings up/down network automatically... Jan 08 00:06:07 main systemd[1]: Started Permit User Sessions. Jan 08 00:06:07 main systemd[1]: Started /etc/rc.local Compatibility. Jan 08 00:06:07 main systemd[1]: Starting Terminate Plymouth Boot Screen... Jan 08 00:06:07 main systemd[1]: Starting Hold until boot process finishes up... Jan 08 00:06:07 main systemd[1]: Received SIGRTMIN+21 from PID 247 (plymouthd). Jan 08 00:06:07 main systemd[1]: Received SIGRTMIN+21 from PID 247 (plymouthd). Jan 08 00:06:07 main systemd[1]: plymouth-quit.service: Succeeded. Jan 08 00:06:07 main systemd[1]: Started Terminate Plymouth Boot Screen. Jan 08 00:06:07 main systemd[1]: plymouth-start.service: Succeeded. Jan 08 00:06:07 main systemd[1]: plymouth-quit-wait.service: Succeeded. Jan 08 00:06:07 main systemd[1]: Started Hold until boot process finishes up. Jan 08 00:06:07 main systemd[1]: Started Getty on tty1. Jan 08 00:06:07 main systemd[1]: Reached target Login Prompts. Jan 08 00:06:07 main ifplugd(eth0)[636]: ifplugd 0.28 initializing. Jan 08 00:06:07 main ifplugd(eth0)[636]: Using interface eth0/DC:A6:32:21:EF:12 with driver (version: v2.0) Jan 08 00:06:07 main ifplugd(eth0)[636]: Using detection mode: SIOCETHTOOL Jan 08 00:06:07 main ifplugd(eth0)[636]: Initialization complete, link beat not detected. Jan 08 00:06:07 main ntpd[609]: ntpd 4.2.8p12@1.3728-o (1): Starting Jan 08 00:06:07 main ntpd[609]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Jan 08 00:06:07 main systemd[1]: Started Network Time Service. Jan 08 00:06:07 main ntpd[638]: proto: precision = 0.778 usec (-20) Jan 08 00:06:07 main ntpd[638]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jan 08 00:06:07 main ntpd[638]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-06-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jan 08 00:06:07 main ntpd[638]: Listen and drop on 0 v6wildcard [::]:123 Jan 08 00:06:07 main ntpd[638]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jan 08 00:06:07 main ntpd[638]: Listen normally on 2 lo 127.0.0.1:123 Jan 08 00:06:07 main ntpd[638]: Listening on routing socket on fd #19 for interface updates Jan 08 00:06:07 main ntpd[638]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 08 00:06:07 main ntpd[638]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 08 00:06:07 main ifplugd[614]: Network Interface Plugging Daemon...start eth0...done. Jan 08 00:06:07 main systemd[1]: Started LSB: Brings up/down network automatically. Jan 08 00:06:07 main haveged[402]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Jan 08 00:06:07 main haveged[402]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Jan 08 00:06:07 main haveged[402]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00117 Jan 08 00:06:07 main haveged[402]: haveged: fills: 0, generated: 0 Jan 08 00:06:07 main kernel: random: crng init done Jan 08 00:06:07 main kernel: random: 7 urandom warning(s) missed due to ratelimiting Jan 08 00:06:08 main nmbd[621]: [2022/01/08 00:06:08.152073, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Jan 08 00:06:08 main nmbd[621]: started asyncdns process 647 Jan 08 00:06:08 main nmbd[621]: [2022/01/08 00:06:08.156360, 0] ../lib/util/become_daemon.c:149(daemon_status) Jan 08 00:06:08 main nmbd[621]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Jan 08 00:06:08 main nmbd[621]: [2022/01/08 00:06:08.156536, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Jan 08 00:06:08 main nmbd[621]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jan 08 00:06:08 main ntpd[638]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jan 08 00:06:08 main wireless.js[442]: WIRELESS DAEMON: start Jan 08 00:06:08 main wireless.js[442]: WIRELESS: Loaded configuration Jan 08 00:06:08 main wireless.js[442]: Cleaning previous... Jan 08 00:06:08 main sudo[652]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 08 00:06:08 main sudo[652]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:08 main sudo[652]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:08 main sudo[654]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 08 00:06:08 main sudo[654]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:09 main mpd[640]: Jan 08 00:06 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 08 00:06:09 main mpd[640]: Jan 08 00:06 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jan 08 00:06:09 main mpd[640]: Jan 08 00:06 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jan 08 00:06:09 main sudo[654]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:09 main systemd[1]: Started Music Player Daemon. Jan 08 00:06:09 main ntpd[638]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jan 08 00:06:09 main wireless.js[442]: Stopped aP Jan 08 00:06:09 main wireless.js[442]: Wireless Networking DISABLED, not starting wireless flow Jan 08 00:06:09 main systemd[1]: wireless.service: Succeeded. Jan 08 00:06:09 main systemd[1]: Started Wireless Services. Jan 08 00:06:09 main systemd[1]: Started Volumio Backend Module. Jan 08 00:06:09 main systemd[1]: Started Volumio Streaming Daemon. Jan 08 00:06:09 main volumio-streaming-daemon[664]: ############################ Jan 08 00:06:09 main volumio-streaming-daemon[664]: # Volumio Streaming Daemon # Jan 08 00:06:09 main volumio-streaming-daemon[664]: # Running on port 7777 # Jan 08 00:06:09 main volumio-streaming-daemon[664]: ############################ Jan 08 00:06:09 main volumio-streaming-daemon[664]: Environment: production Jan 08 00:06:09 main systemd[1]: systemd-rfkill.service: Succeeded. Jan 08 00:06:10 main ntpd[638]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jan 08 00:06:11 main sh[394]: eth0: carrier acquired Jan 08 00:06:11 main dhcpcd[416]: eth0: carrier acquired Jan 08 00:06:11 main kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off Jan 08 00:06:11 main sh[394]: DUID 00:01:00:01:29:4a:1c:70:dc:a6:32:21:ef:12 Jan 08 00:06:11 main sh[394]: eth0: IAID 32:21:ef:12 Jan 08 00:06:11 main sh[394]: eth0: adding address fe80::dea6:32ff:fe21:ef12 Jan 08 00:06:11 main sh[394]: ipv6_addaddr1: Permission denied Jan 08 00:06:11 main dhcpcd[416]: DUID 00:01:00:01:29:4a:1c:70:dc:a6:32:21:ef:12 Jan 08 00:06:11 main dhcpcd[416]: eth0: IAID 32:21:ef:12 Jan 08 00:06:11 main dhcpcd[416]: eth0: adding address fe80::dea6:32ff:fe21:ef12 Jan 08 00:06:11 main dhcpcd[416]: ipv6_addaddr1: Permission denied Jan 08 00:06:11 main volumio[663]: info: ------------------------------------------- Jan 08 00:06:11 main volumio[663]: info: ----- Volumio3 ---- Jan 08 00:06:11 main volumio[663]: info: ------------------------------------------- Jan 08 00:06:11 main volumio[663]: info: ----- System startup ---- Jan 08 00:06:11 main volumio[663]: info: ------------------------------------------- Jan 08 00:06:11 main sh[394]: eth0: soliciting a DHCP lease Jan 08 00:06:11 main dhcpcd[416]: eth0: soliciting a DHCP lease Jan 08 00:06:11 main ntpd[638]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jan 08 00:06:11 main ifplugd(eth0)[636]: Link beat detected. Jan 08 00:06:11 main ifplugd(eth0)[636]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Jan 08 00:06:11 main ifplugd(eth0)[636]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Jan 08 00:06:11 main volumio-remote-updater[454]: [2022-01-08 00:06:11] [connect] Successful connection Jan 08 00:06:12 main volumio[663]: info: MYVOLUMIO Environment detected Jan 08 00:06:12 main volumio[663]: info: Plugin folders cleanup Jan 08 00:06:12 main volumio[663]: info: Scanning into folder /volumio/app/plugins/ Jan 08 00:06:12 main volumio[663]: info: Scanning category audio_interface Jan 08 00:06:12 main volumio[663]: info: Scanning category miscellanea Jan 08 00:06:12 main volumio[663]: info: Scanning category music_service Jan 08 00:06:12 main volumio[663]: info: Scanning category plugins.json Jan 08 00:06:12 main volumio[663]: info: Scanning category system_controller Jan 08 00:06:12 main volumio[663]: info: Scanning category user_interface Jan 08 00:06:12 main volumio[663]: info: Scanning into folder /data/plugins/ Jan 08 00:06:12 main volumio[663]: info: Scanning category music_service Jan 08 00:06:12 main volumio[663]: info: Scanning category user_interface Jan 08 00:06:12 main volumio[663]: info: Plugin folders cleanup completed Jan 08 00:06:12 main volumio[663]: info: ------------------------------------------- Jan 08 00:06:12 main volumio[663]: info: ----- Core plugins startup ---- Jan 08 00:06:12 main volumio[663]: info: ------------------------------------------- Jan 08 00:06:12 main volumio[663]: info: Loading plugins from folder /volumio/app/plugins/ Jan 08 00:06:12 main volumio[663]: info: Adding plugin upnp to MyMusic Plugins Jan 08 00:06:12 main volumio[663]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 08 00:06:12 main volumio[663]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 08 00:06:12 main volumio[663]: info: Loading plugins from folder /data/plugins/ Jan 08 00:06:12 main volumio[663]: info: Loading plugin "system"... Jan 08 00:06:12 main volumio[663]: info: Loading plugin "appearance"... Jan 08 00:06:12 main sh[394]: eth0: soliciting an IPv6 router Jan 08 00:06:12 main dhcpcd[416]: eth0: soliciting an IPv6 router Jan 08 00:06:12 main kernel: Bluetooth: Core ver 2.22 Jan 08 00:06:12 main kernel: NET: Registered protocol family 31 Jan 08 00:06:12 main kernel: Bluetooth: HCI device and connection manager initialized Jan 08 00:06:12 main kernel: Bluetooth: HCI socket layer initialized Jan 08 00:06:12 main kernel: Bluetooth: L2CAP socket layer initialized Jan 08 00:06:12 main kernel: Bluetooth: SCO socket layer initialized Jan 08 00:06:12 main btuart[440]: bcm43xx_init Jan 08 00:06:12 main btuart[440]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd Jan 08 00:06:12 main btuart[440]: Set Controller UART speed to 3000000 bit/s Jan 08 00:06:12 main btuart[440]: Device setup complete Jan 08 00:06:12 main kernel: Bluetooth: HCI UART driver ver 2.3 Jan 08 00:06:12 main kernel: Bluetooth: HCI UART protocol H4 registered Jan 08 00:06:12 main kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Jan 08 00:06:12 main kernel: Bluetooth: HCI UART protocol Broadcom registered Jan 08 00:06:12 main systemd[1]: Starting Load/Save RF Kill Switch Status... Jan 08 00:06:12 main systemd[1]: Started Configure Bluetooth Modems connected by UART. Jan 08 00:06:12 main systemd[1]: Started Load/Save RF Kill Switch Status. Jan 08 00:06:12 main systemd[1]: Created slice system-bthelper.slice. Jan 08 00:06:12 main systemd[1]: Starting Raspberry Pi bluetooth helper... Jan 08 00:06:12 main bthelper[701]: Raspberry Pi BDADDR already set Jan 08 00:06:12 main systemd[1]: Started Raspberry Pi bluetooth helper. Jan 08 00:06:12 main systemd[1]: Starting Bluetooth service... Jan 08 00:06:12 main bluetoothd[711]: Bluetooth daemon 5.50 Jan 08 00:06:12 main bluetoothd[711]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Jan 08 00:06:12 main systemd[1]: Started Bluetooth service. Jan 08 00:06:12 main systemd[1]: Reached target Bluetooth. Jan 08 00:06:12 main bluetoothd[711]: Starting SDP server Jan 08 00:06:12 main bluetoothd[711]: Excluding (cli) sap Jan 08 00:06:12 main kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Jan 08 00:06:12 main kernel: Bluetooth: BNEP filters: protocol multicast Jan 08 00:06:12 main kernel: Bluetooth: BNEP socket layer initialized Jan 08 00:06:12 main bluetoothd[711]: Bluetooth management interface 1.14 initialized Jan 08 00:06:12 main dbus-daemon[447]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=711 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Jan 08 00:06:13 main systemd[1]: Starting Hostname Service... Jan 08 00:06:13 main bluetoothd[711]: Failed to set privacy: Rejected (0x0b) Jan 08 00:06:13 main dbus-daemon[447]: [system] Successfully activated service 'org.freedesktop.hostname1' Jan 08 00:06:13 main systemd[1]: Started Hostname Service. Jan 08 00:06:13 main volumio[663]: info: Loading plugin "network"... Jan 08 00:06:13 main volumio[663]: info: Refreshing Cached IP Addresses Jan 08 00:06:13 main sudo[715]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:06:13 main sudo[715]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:13 main volumio[663]: info: Loading plugin "services"... Jan 08 00:06:13 main volumio[663]: info: Loading plugin "alsa_controller"... Jan 08 00:06:13 main sudo[715]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:13 main sudo[717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:06:13 main sudo[717]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:13 main sudo[717]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:13 main volumio[663]: info: Loading plugin "wizard"... Jan 08 00:06:13 main volumio[663]: info: Loading plugin "volumio_command_line_client"... Jan 08 00:06:13 main volumio[663]: info: Loading plugin "upnp"... Jan 08 00:06:13 main volumio[663]: info: [1641600373330] Starting Upmpd Daemon Jan 08 00:06:13 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 00:06:13 main volumio[663]: info: Loading plugin "my_music"... Jan 08 00:06:13 main volumio[663]: info: Loading plugin "mpd"... Jan 08 00:06:13 main volumio[663]: info: Creating MPD Configuration file Jan 08 00:06:13 main volumio[663]: info: Loading plugin "upnp_browser"... Jan 08 00:06:13 main sudo[725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 00:06:13 main sudo[725]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:13 main sudo[725]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:13 main sudo[727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 00:06:13 main sudo[727]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:13 main systemd[1]: Stopping Music Player Daemon... Jan 08 00:06:13 main systemd[1]: mpd.service: Succeeded. Jan 08 00:06:13 main systemd[1]: Stopped Music Player Daemon. Jan 08 00:06:13 main systemd[1]: Starting Music Player Daemon... Jan 08 00:06:13 main volumio[663]: info: Loading plugin "networkfs"... Jan 08 00:06:14 main volumio[663]: info: Starting Udev Watcher for removable devices Jan 08 00:06:14 main volumio[663]: info: Ignoring mount for partition: boot Jan 08 00:06:14 main volumio[663]: info: Ignoring mount for partition: volumio Jan 08 00:06:14 main volumio[663]: info: Ignoring mount for partition: volumio_data Jan 08 00:06:14 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 00:06:14 main volumio[663]: info: Loading plugin "alarm-clock"... Jan 08 00:06:14 main mpd[732]: Jan 08 00:06 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 08 00:06:14 main mpd[732]: Jan 08 00:06 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jan 08 00:06:14 main mpd[732]: Jan 08 00:06 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jan 08 00:06:14 main systemd[1]: Started Music Player Daemon. Jan 08 00:06:14 main sudo[727]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:14 main volumio[663]: info: Loading plugin "airplay_emulation"... Jan 08 00:06:14 main volumio[663]: info: Starting Shairport Sync Jan 08 00:06:14 main volumio[663]: info: Loading plugin "last_100"... Jan 08 00:06:14 main volumio[663]: info: Loading plugin "webradio"... Jan 08 00:06:14 main volumio[663]: info: Loading plugin "i2s_dacs"... Jan 08 00:06:14 main volumio[663]: info: I2S DAC not set, start Auto-detection Jan 08 00:06:14 main volumio[663]: info: Loading plugin "volumiodiscovery"... Jan 08 00:06:14 main volumio[663]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 00:06:14 main node[663]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 08 00:06:14 main volumio[663]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 00:06:14 main node[663]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 00:06:14 main volumio[663]: *** WARNING *** For more information see Jan 08 00:06:14 main node[663]: *** WARNING *** For more information see Jan 08 00:06:14 main volumio[663]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 00:06:14 main node[663]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 08 00:06:14 main volumio[663]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 00:06:14 main node[663]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 08 00:06:14 main volumio[663]: *** WARNING *** For more information see Jan 08 00:06:14 main node[663]: *** WARNING *** For more information see Jan 08 00:06:14 main volumio[663]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 08 00:06:14 main volumio[663]: info: Discovery: Started advertising with name: Main Jan 08 00:06:14 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 00:06:14 main volumio[663]: info: Loading plugin "ytcr"... Jan 08 00:06:16 main volumio[663]: info: Loading plugin "outputs"... Jan 08 00:06:16 main volumio[663]: info: Loading plugin "albumart"... Jan 08 00:06:16 main volumio[663]: info: Plugin example_plugin is not enabled Jan 08 00:06:16 main volumio[663]: info: Loading plugin "inputs"... Jan 08 00:06:16 main volumio[663]: info: Loading plugin "updater_comm"... Jan 08 00:06:16 main sh[394]: eth0: probing for an IPv4LL address Jan 08 00:06:16 main dhcpcd[416]: eth0: probing for an IPv4LL address Jan 08 00:06:16 main volumio[663]: info: Plugin mpdemulation is not enabled Jan 08 00:06:16 main volumio[663]: info: Loading plugin "rest_api"... Jan 08 00:06:16 main volumio[663]: info: Loading plugin "websocket"... Jan 08 00:06:16 main volumio[663]: info: Loading plugin "volspotconnect2"... Jan 08 00:06:16 main volumio[663]: Forking 3 albumart workers Jan 08 00:06:17 main volumio[663]: Starting albumart workers Jan 08 00:06:17 main volumio[663]: Starting albumart workers Jan 08 00:06:17 main volumio[663]: Starting albumart workers Jan 08 00:06:17 main volumio[663]: info: Loading plugin "touch_display"... Jan 08 00:06:17 main volumio[663]: info: Applying required configuration parameters for plugin touch_display Jan 08 00:06:17 main volumio[663]: info: Loading i18n strings for locale en Jan 08 00:06:17 main volumio[663]: Updating browse sources language Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::initPlayerControls Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:06:17 main volumio[663]: Express server listening on port 3000 Jan 08 00:06:17 main volumio[663]: [Metrics] WebUI: 7s 60.00ms Jan 08 00:06:17 main volumio[663]: info: CoreStateMachine::resetVolumioState Jan 08 00:06:17 main volumio[663]: info: CoreStateMachine::getcurrentVolume Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:06:17 main systemd[1]: systemd-rfkill.service: Succeeded. Jan 08 00:06:17 main volumio[663]: info: MPD Permissions set Jan 08 00:06:17 main bthelper[701]: Changing power off succeeded Jan 08 00:06:17 main volumio[663]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 Jan 08 00:06:17 main volumio[663]: info: MPD running with PID732 Jan 08 00:06:17 main volumio[663]: ,establishing connection Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: Reloading queue from file Jan 08 00:06:18 main volumio[663]: error: updateQueue error: null Jan 08 00:06:18 main volumio[663]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 08 00:06:18 main volumio[663]: info: VolumeController:: Volume=100 Mute =false Jan 08 00:06:18 main volumio[663]: info: CoreStateMachine::pushState Jan 08 00:06:18 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::volumioPushState Jan 08 00:06:18 main volumio[663]: info: CoreStateMachine::updateTrackBlock Jan 08 00:06:18 main volumio[663]: info: CorePlayQueue::getTrackBlock Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::volumioRetrievevolume Jan 08 00:06:18 main volumio[663]: info: CoreStateMachine::setRepeat null single undefined Jan 08 00:06:18 main volumio[663]: info: CoreStateMachine::pushState Jan 08 00:06:18 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::volumioPushState Jan 08 00:06:18 main volumio[663]: info: CoreStateMachine::setRandom null Jan 08 00:06:18 main volumio[663]: info: CoreStateMachine::pushState Jan 08 00:06:18 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::volumioPushState Jan 08 00:06:18 main volumio[663]: info: Setting Device type: Raspberry PI Jan 08 00:06:18 main volumio[663]: error: updateQueue error: null Jan 08 00:06:18 main bthelper[701]: [CHG] Controller DC:A6:32:21:EF:14 Class: 0x0000041c Jan 08 00:06:18 main bthelper[701]: Changing power on succeeded Jan 08 00:06:18 main volumio[663]: info: Completed loading Core Plugins Jan 08 00:06:18 main volumio[663]: info: Preparing to generate the ALSA configuration file Jan 08 00:06:18 main volumio[663]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 08 00:06:18 main volumio[663]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 08 00:06:18 main volumio[663]: info: Reading ALSA contributions from plugins. Jan 08 00:06:18 main volumio[663]: info: VolumeController:: Volume=100 Mute =false Jan 08 00:06:18 main volumio[663]: info: CoreStateMachine::pushState Jan 08 00:06:18 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::volumioPushState Jan 08 00:06:18 main volumio[663]: info: Asound.conf file unchanged, so no further update is needed Jan 08 00:06:18 main volumio[663]: info: Output device has changed, restarting MPD Jan 08 00:06:18 main sudo[815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 00:06:18 main volumio[663]: info: Output device has changed, restarting Shairport Sync Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:06:18 main sudo[815]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:18 main sudo[815]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:18 main sudo[817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 00:06:18 main sudo[817]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:18 main systemd[1]: Stopping Music Player Daemon... Jan 08 00:06:18 main systemd[1]: mpd.service: Succeeded. Jan 08 00:06:18 main volumio[663]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 00:06:18 main systemd[1]: Stopped Music Player Daemon. Jan 08 00:06:18 main volumio[663]: info: ___________ START PLUGINS ___________ Jan 08 00:06:18 main systemd[1]: Starting Music Player Daemon... Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 00:06:18 main volumio[663]: info: [1641600378267] CoreMusicLibrary::Adding element Media Servers Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:06:18 main volumio[663]: Cannot find translation for sourceMedia Servers Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:06:18 main volumio[663]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:06:18 main volumio[663]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 00:06:18 main volumio[663]: info: [1641600378356] CoreMusicLibrary::Adding element Last_100 Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:06:18 main volumio[663]: Cannot find translation for sourceMedia Servers Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 00:06:18 main volumio[663]: info: [1641600378359] CoreMusicLibrary::Adding element Webradio Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:06:18 main volumio[663]: Cannot find translation for sourceMedia Servers Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 00:06:18 main volumio[663]: [SpotifyConnect] Creating VLS config file Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: [SpotifyConnect] Starting metadata listener Jan 08 00:06:18 main volumio[663]: info: Loading i18n strings for locale en Jan 08 00:06:18 main sudo[833]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect2.service Jan 08 00:06:18 main sudo[833]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:18 main volumio[663]: info: Volumio Calling Home Jan 08 00:06:18 main systemd[1]: Started Volspotconnect2 Daemon. Jan 08 00:06:18 main sudo[836]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 08 00:06:18 main sudo[836]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:18 main sudo[833]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:18 main systemd[1]: Reloading. Jan 08 00:06:18 main volumio[838]: vollibrespot v0.2.3 769ce77 2021-06-04 (librespot 08d8bcc 2020-10-07) -- Built On 2021-06-04 Jan 08 00:06:18 main volumio[838]: Reading Config from "volspotify.toml" Jan 08 00:06:18 main volumio[838]: [Vollibrespot] : Using Alsa backend with device: volumio Jan 08 00:06:18 main volumio[838]: thread 'main' panicked at 'Discovery error!: Os { code: 19, kind: Other, message: "No such device" }', src/main.rs:223:76 Jan 08 00:06:18 main volumio[838]: stack backtrace: Jan 08 00:06:18 main volumio[663]: Unhandled rejection Error: No sockets available, cannot start. Jan 08 00:06:18 main volumio[663]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Jan 08 00:06:18 main volumio[663]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Jan 08 00:06:18 main volumio[663]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Jan 08 00:06:18 main volumio[663]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Jan 08 00:06:18 main volumio[663]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Jan 08 00:06:18 main volumio[663]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Jan 08 00:06:18 main volumio[663]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Jan 08 00:06:18 main volumio[663]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Jan 08 00:06:18 main volumio[663]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Jan 08 00:06:18 main volumio[663]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Jan 08 00:06:18 main volumio[663]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Jan 08 00:06:18 main volumio[663]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jan 08 00:06:18 main volumio[663]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jan 08 00:06:18 main volumio[663]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Jan 08 00:06:18 main volumio[663]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Jan 08 00:06:18 main volumio[663]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jan 08 00:06:18 main volumio[663]: [SpotifyConnect] Vollibrespot Daemon service started! Jan 08 00:06:18 main volumio[663]: [Metrics] SpotifyConnect: 0s 340.18ms Jan 08 00:06:18 main volumio[663]: info: MPD Permissions set Jan 08 00:06:18 main volumio[663]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:18 main volumio[838]: 0: 0xa27040 - std::backtrace_rs::backtrace::libunwind::trace::h4e6fc6cdc5d76862 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5 Jan 08 00:06:18 main volumio[838]: 1: 0xa27040 - std::backtrace_rs::backtrace::trace_unsynchronized::h1c665adaaf480d86 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5 Jan 08 00:06:18 main volumio[838]: 2: 0xa27040 - std::sys_common::backtrace::_print_fmt::h39ff02745027e048 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:67:5 Jan 08 00:06:18 main volumio[838]: 3: 0xa27040 - ::fmt::hc83ae421f857c6ae Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:46:22 Jan 08 00:06:18 main systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Jan 08 00:06:18 main volumio[838]: 4: 0xa486a4 - core::fmt::write::h59f33d28fc1a9cf5 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/fmt/mod.rs:1092:17 Jan 08 00:06:18 main volumio[838]: 5: 0xa1ffec - std::io::Write::write_fmt::h96774110acd52d88 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/io/mod.rs:1572:15 Jan 08 00:06:18 main volumio[838]: 6: 0xa2974c - std::sys_common::backtrace::_print::h28b9431057012c44 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:49:5 Jan 08 00:06:18 main volumio[838]: 7: 0xa2974c - std::sys_common::backtrace::print::h28173b7ebfe4a4ac Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:36:9 Jan 08 00:06:18 main volumio[838]: 8: 0xa2974c - std::panicking::default_hook::{{closure}}::h12f82aa3def34336 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:208:50 Jan 08 00:06:18 main volumio[838]: 9: 0xa2912c - std::panicking::default_hook::hee29440c29c1cc2e Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:225:9 Jan 08 00:06:18 main volumio[838]: 10: 0xa29dac - std::panicking::rust_panic_with_hook::he7d3b6e3eee77e72 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:591:17 Jan 08 00:06:18 main volumio[838]: 11: 0xa29928 - std::panicking::begin_panic_handler::{{closure}}::h7faba6b3632756a6 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:497:13 Jan 08 00:06:18 main volumio[838]: 12: 0xa275bc - std::sys_common::backtrace::__rust_end_short_backtrace::hdde0f982a7a71ce9 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:141:18 Jan 08 00:06:18 main volumio[838]: 13: 0xa29870 - rust_begin_unwind Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:493:5 Jan 08 00:06:18 main volumio[838]: 14: 0x50321c - core::panicking::panic_fmt::h97b6949f75a63095 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/panicking.rs:92:14 Jan 08 00:06:18 main volumio[838]: 15: 0x503120 - core::option::expect_none_failed::h4525992415ba2383 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/option.rs:1329:5 Jan 08 00:06:18 main volumio[838]: 16: 0x529918 - vollibrespot::main::hf11cedd7d8a3be51 Jan 08 00:06:18 main volumio[838]: 17: 0x55c500 - std::sys_common::backtrace::__rust_begin_short_backtrace::ha48b0377a890cb6d Jan 08 00:06:18 main volumio[838]: 18: 0x55c720 - std::rt::lang_start::{{closure}}::h120c4b14d2445a8e Jan 08 00:06:18 main volumio[838]: 19: 0xa2a198 - core::ops::function::impls:: for &F>::call_once::hb7f0eab2b8615017 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/ops/function.rs:259:13 Jan 08 00:06:18 main volumio[838]: 20: 0xa2a198 - std::panicking::try::do_call::h2c625414401a1a99 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:379:40 Jan 08 00:06:18 main volumio[838]: 21: 0xa2a198 - std::panicking::try::h09167d835e285a07 Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:343:19 Jan 08 00:06:18 main volumio[838]: 22: 0xa2a198 - std::panic::catch_unwind::hdff19ee37d8421eb Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panic.rs:431:14 Jan 08 00:06:18 main volumio[838]: 23: 0xa2a198 - std::rt::lang_start_internal::h835544f25e1ef31c Jan 08 00:06:18 main volumio[838]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/rt.rs:51:25 Jan 08 00:06:18 main volumio[838]: 24: 0x52aa08 - main Jan 08 00:06:18 main volumio[838]: 25: 0xb6bf2718 - __libc_start_main Jan 08 00:06:18 main volumio[663]: info: Starting Shairport Sync Jan 08 00:06:18 main volumio[663]: info: Starting Shairport Sync Jan 08 00:06:18 main sudo[864]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 00:06:18 main volumio[663]: info: Starting Shairport Sync Jan 08 00:06:18 main sudo[864]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:18 main sudo[867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 00:06:18 main sudo[867]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:18 main sudo[869]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 00:06:18 main sudo[869]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:18 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:06:18 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:18 main systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Jan 08 00:06:18 main systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Jan 08 00:06:19 main mpd[831]: Jan 08 00:06 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 08 00:06:19 main mpd[831]: Jan 08 00:06 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jan 08 00:06:19 main mpd[831]: Jan 08 00:06 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jan 08 00:06:19 main systemd[1]: Started Music Player Daemon. Jan 08 00:06:19 main systemd[1]: volspotconnect2.service: Main process exited, code=exited, status=101/n/a Jan 08 00:06:19 main systemd[1]: volspotconnect2.service: Failed with result 'exit-code'. Jan 08 00:06:19 main sudo[836]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:19 main sudo[817]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:19 main volumio[663]: info: touch_display: systemctl daemon-reload succeeded. Jan 08 00:06:19 main volumio[663]: error: updateQueue error: null Jan 08 00:06:19 main sudo[875]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Jan 08 00:06:19 main sudo[875]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:19 main systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 08 00:06:19 main systemd[1]: shairport-sync.service: Succeeded. Jan 08 00:06:19 main systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 08 00:06:19 main systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 08 00:06:19 main sudo[864]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:19 main sudo[867]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:19 main sudo[869]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:19 main volumio[663]: info: Shairport-Sync Started Jan 08 00:06:19 main volumio[663]: Error adding Membership: Error: addMembership EINVAL Jan 08 00:06:19 main volumio[663]: info: Shairport-Sync Started Jan 08 00:06:19 main volumio[663]: info: Shairport-Sync Started Jan 08 00:06:19 main systemd[1]: Started Volumio Kiosk. Jan 08 00:06:19 main sudo[875]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:19 main volumio[663]: [yt-cast-receiver] Listening on port 8098 Jan 08 00:06:19 main volumio[663]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Jan 08 00:06:19 main volumio[663]: info: touch_display: Volumio Kiosk started Jan 08 00:06:19 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 00:06:19 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:06:19 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:19 main volumio[663]: info: Completed starting Core Plugins Jan 08 00:06:19 main volumio[663]: info: ------------------------------------------- Jan 08 00:06:19 main volumio[663]: info: ----- MyVolumio plugins startup ---- Jan 08 00:06:19 main volumio[663]: info: ------------------------------------------- Jan 08 00:06:19 main volumio[663]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 08 00:06:19 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:06:19 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:19 main volumio[663]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Jan 08 00:06:19 main volumio[663]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jan 08 00:06:19 main startx[878]: X.Org X Server 1.20.4 Jan 08 00:06:19 main startx[878]: X Protocol Version 11, Revision 0 Jan 08 00:06:19 main startx[878]: Build Operating System: Linux 5.10.17-v8+ aarch64 Raspbian Jan 08 00:06:19 main startx[878]: Current Operating System: Linux main 5.4.83-v7l+ #1379 SMP Mon Dec 14 13:11:54 GMT 2020 armv7l Jan 08 00:06:19 main startx[878]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=1920 bcm2708_fb.fbheight=1280 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:21:EF:12 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh rootwait bootdelay=5 elevator=noop logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 loglevel=0 Jan 08 00:06:19 main startx[878]: Build Date: 19 April 2021 03:23:36PM Jan 08 00:06:19 main startx[878]: xorg-server 2:1.20.4-1+rpt3+deb10u3 (https://www.debian.org/support) Jan 08 00:06:19 main startx[878]: Current version of pixman: 0.36.0 Jan 08 00:06:19 main startx[878]: Before reporting problems, check http://wiki.x.org Jan 08 00:06:19 main startx[878]: to make sure that you have the latest version. Jan 08 00:06:19 main startx[878]: Markers: (--) probed, (**) from config file, (==) default setting, Jan 08 00:06:19 main startx[878]: (++) from command line, (!!) notice, (II) informational, Jan 08 00:06:19 main startx[878]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jan 08 00:06:19 main startx[878]: (==) Log file: "/var/log/Xorg.0.log", Time: Sat Jan 8 00:06:19 2022 Jan 08 00:06:19 main sudo[905]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i -e /Option "TransformationMatrix"/d /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Jan 08 00:06:19 main sudo[905]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:19 main startx[878]: (==) Using config directory: "/etc/X11/xorg.conf.d" Jan 08 00:06:19 main startx[878]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jan 08 00:06:19 main sudo[905]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:19 main volumio[663]: info: touch_display: Touchscreen transformation matrix removed. Jan 08 00:06:19 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:06:19 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:19 main volumio[663]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jan 08 00:06:20 main startx[878]: [1B blob data] Jan 08 00:06:20 main volumio[663]: error: touch_display: Error setting screensaver timeout: Error: Command failed: /usr/bin/xset -display :0 s off +dpms dpms 0 0 0 Jan 08 00:06:20 main volumio[663]: /usr/bin/xset: unable to open display ":0" Jan 08 00:06:20 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:06:20 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:20 main volumio[663]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jan 08 00:06:21 main systemd[1]: volspotconnect2.service: Service RestartSec=2s expired, scheduling restart. Jan 08 00:06:21 main systemd[1]: volspotconnect2.service: Scheduled restart job, restart counter is at 1. Jan 08 00:06:21 main systemd[1]: Stopped Volspotconnect2 Daemon. Jan 08 00:06:21 main systemd[1]: Started Volspotconnect2 Daemon. Jan 08 00:06:21 main volumio[940]: vollibrespot v0.2.3 769ce77 2021-06-04 (librespot 08d8bcc 2020-10-07) -- Built On 2021-06-04 Jan 08 00:06:21 main volumio[940]: Reading Config from "volspotify.toml" Jan 08 00:06:21 main volumio[940]: [Vollibrespot] : Using Alsa backend with device: volumio Jan 08 00:06:21 main volumio[940]: thread 'main' panicked at 'Discovery error!: Os { code: 19, kind: Other, message: "No such device" }', src/main.rs:223:76 Jan 08 00:06:21 main volumio[940]: stack backtrace: Jan 08 00:06:21 main volumio[940]: 0: 0x9be040 - std::backtrace_rs::backtrace::libunwind::trace::h4e6fc6cdc5d76862 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5 Jan 08 00:06:21 main volumio[940]: 1: 0x9be040 - std::backtrace_rs::backtrace::trace_unsynchronized::h1c665adaaf480d86 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5 Jan 08 00:06:21 main volumio[940]: 2: 0x9be040 - std::sys_common::backtrace::_print_fmt::h39ff02745027e048 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:67:5 Jan 08 00:06:21 main volumio[940]: 3: 0x9be040 - ::fmt::hc83ae421f857c6ae Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:46:22 Jan 08 00:06:21 main volumio[940]: 4: 0x9df6a4 - core::fmt::write::h59f33d28fc1a9cf5 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/fmt/mod.rs:1092:17 Jan 08 00:06:21 main volumio[940]: 5: 0x9b6fec - std::io::Write::write_fmt::h96774110acd52d88 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/io/mod.rs:1572:15 Jan 08 00:06:21 main volumio[940]: 6: 0x9c074c - std::sys_common::backtrace::_print::h28b9431057012c44 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:49:5 Jan 08 00:06:21 main volumio[940]: 7: 0x9c074c - std::sys_common::backtrace::print::h28173b7ebfe4a4ac Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:36:9 Jan 08 00:06:21 main volumio[940]: 8: 0x9c074c - std::panicking::default_hook::{{closure}}::h12f82aa3def34336 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:208:50 Jan 08 00:06:21 main volumio[940]: 9: 0x9c012c - std::panicking::default_hook::hee29440c29c1cc2e Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:225:9 Jan 08 00:06:21 main volumio[940]: 10: 0x9c0dac - std::panicking::rust_panic_with_hook::he7d3b6e3eee77e72 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:591:17 Jan 08 00:06:21 main volumio[940]: 11: 0x9c0928 - std::panicking::begin_panic_handler::{{closure}}::h7faba6b3632756a6 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:497:13 Jan 08 00:06:21 main volumio[940]: 12: 0x9be5bc - std::sys_common::backtrace::__rust_end_short_backtrace::hdde0f982a7a71ce9 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:141:18 Jan 08 00:06:21 main volumio[940]: 13: 0x9c0870 - rust_begin_unwind Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:493:5 Jan 08 00:06:21 main volumio[940]: 14: 0x49a21c - core::panicking::panic_fmt::h97b6949f75a63095 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/panicking.rs:92:14 Jan 08 00:06:21 main volumio[940]: 15: 0x49a120 - core::option::expect_none_failed::h4525992415ba2383 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/option.rs:1329:5 Jan 08 00:06:21 main volumio[940]: 16: 0x4c0918 - vollibrespot::main::hf11cedd7d8a3be51 Jan 08 00:06:21 main volumio[940]: 17: 0x4f3500 - std::sys_common::backtrace::__rust_begin_short_backtrace::ha48b0377a890cb6d Jan 08 00:06:21 main volumio[940]: 18: 0x4f3720 - std::rt::lang_start::{{closure}}::h120c4b14d2445a8e Jan 08 00:06:21 main volumio[940]: 19: 0x9c1198 - core::ops::function::impls:: for &F>::call_once::hb7f0eab2b8615017 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/ops/function.rs:259:13 Jan 08 00:06:21 main volumio[940]: 20: 0x9c1198 - std::panicking::try::do_call::h2c625414401a1a99 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:379:40 Jan 08 00:06:21 main volumio[940]: 21: 0x9c1198 - std::panicking::try::h09167d835e285a07 Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:343:19 Jan 08 00:06:21 main volumio[940]: 22: 0x9c1198 - std::panic::catch_unwind::hdff19ee37d8421eb Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panic.rs:431:14 Jan 08 00:06:21 main volumio[940]: 23: 0x9c1198 - std::rt::lang_start_internal::h835544f25e1ef31c Jan 08 00:06:21 main volumio[940]: at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/rt.rs:51:25 Jan 08 00:06:21 main volumio[940]: 24: 0x4c1a08 - main Jan 08 00:06:21 main volumio[940]: 25: 0xb6c6f718 - __libc_start_main Jan 08 00:06:21 main systemd[1]: volspotconnect2.service: Main process exited, code=exited, status=101/n/a Jan 08 00:06:21 main systemd[1]: volspotconnect2.service: Failed with result 'exit-code'. Jan 08 00:06:21 main volumio[663]: error: touch_display: Error setting screensaver timeout: Error: Command failed: /usr/bin/xset -display :0 s off +dpms dpms 0 0 0 Jan 08 00:06:21 main volumio[663]: /usr/bin/xset: unable to open display ":0" Jan 08 00:06:21 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:06:21 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:21 main volumio[663]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jan 08 00:06:21 main sh[394]: eth0: using IPv4LL address 169.254.193.92 Jan 08 00:06:21 main sh[394]: eth0: adding route to 169.254.0.0/16 Jan 08 00:06:21 main sh[394]: eth0: adding default route Jan 08 00:06:21 main dhcpcd[416]: eth0: using IPv4LL address 169.254.193.92 Jan 08 00:06:21 main dhcpcd[416]: eth0: adding route to 169.254.0.0/16 Jan 08 00:06:21 main dhcpcd[416]: eth0: adding default route Jan 08 00:06:21 main avahi-daemon[459]: Joining mDNS multicast group on interface eth0.IPv4 with address 169.254.193.92. Jan 08 00:06:21 main avahi-daemon[459]: New relevant interface eth0.IPv4 for mDNS. Jan 08 00:06:21 main avahi-daemon[459]: Registering new address record for 169.254.193.92 on eth0.IPv4. Jan 08 00:06:21 main sh[394]: forked to background, child pid 960 Jan 08 00:06:21 main dhcpcd[416]: forked to background, child pid 960 Jan 08 00:06:22 main ifplugd(eth0)[636]: client: ifup: interface eth0 already configured Jan 08 00:06:22 main sh[394]: eth0=eth0 Jan 08 00:06:22 main ifplugd(eth0)[636]: Program executed successfully. Jan 08 00:06:22 main startx[878]: waiting for X server to begin accepting connections . Jan 08 00:06:22 main volumio[663]: error: touch_display: Error setting screensaver timeout: Error: Command failed: /usr/bin/xset -display :0 s off +dpms dpms 0 0 0 Jan 08 00:06:22 main volumio[663]: /usr/bin/xset: unable to open display ":0" Jan 08 00:06:22 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:06:22 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:22 main volumio[663]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jan 08 00:06:23 main nmbd[621]: [2022/01/08 00:06:23.160295, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 08 00:06:23 main nmbd[621]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jan 08 00:06:23 main systemd[1]: Started Samba NMB Daemon. Jan 08 00:06:23 main systemd[1]: Starting Samba Winbind Daemon... Jan 08 00:06:23 main winbindd[1014]: [2022/01/08 00:06:23.355922, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jan 08 00:06:23 main winbindd[1014]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jan 08 00:06:23 main sudo[1018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:06:23 main sudo[1018]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:23 main sudo[1018]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:23 main sudo[1020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:06:23 main winbindd[1014]: [2022/01/08 00:06:23.383852, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 08 00:06:23 main winbindd[1014]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jan 08 00:06:23 main systemd[1]: Started Samba Winbind Daemon. Jan 08 00:06:23 main sudo[1020]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:23 main systemd[1]: Starting Samba SMB Daemon... Jan 08 00:06:23 main sudo[1020]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:23 main sudo[1023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 08 00:06:23 main sudo[1023]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:06:23 main systemd[1]: volspotconnect2.service: Service RestartSec=2s expired, scheduling restart. Jan 08 00:06:23 main systemd[1]: volspotconnect2.service: Scheduled restart job, restart counter is at 2. Jan 08 00:06:23 main systemd[1]: Stopped Volspotconnect2 Daemon. Jan 08 00:06:23 main systemd[1]: Started Volspotconnect2 Daemon. Jan 08 00:06:23 main volumio[1028]: vollibrespot v0.2.3 769ce77 2021-06-04 (librespot 08d8bcc 2020-10-07) -- Built On 2021-06-04 Jan 08 00:06:23 main volumio[1028]: Reading Config from "volspotify.toml" Jan 08 00:06:23 main volumio[1028]: [Vollibrespot] : Using Alsa backend with device: volumio Jan 08 00:06:23 main systemd[1]: Started UPnP Renderer front-end to MPD. Jan 08 00:06:23 main sudo[1023]: pam_unix(sudo:session): session closed for user root Jan 08 00:06:23 main volumio[663]: info: Upmpdcli Daemon Started Jan 08 00:06:23 main volumio[663]: info: touch_display: Setting screensaver timeout to 0 seconds. Jan 08 00:06:23 main volumio[1028]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } Jan 08 00:06:23 main ntpd[638]: Listen normally on 3 eth0 169.254.193.92:123 Jan 08 00:06:23 main ntpd[638]: new interface(s) found: waking up resolver Jan 08 00:06:23 main volumio[1032]: Generating RSA private key, 4096 bit long modulus (2 primes) Jan 08 00:06:23 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:06:23 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:23 main volumio[663]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jan 08 00:06:23 main winbindd[1014]: [2022/01/08 00:06:23.767633, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Jan 08 00:06:23 main winbindd[1014]: res_names->count = 3, expected 4 Jan 08 00:06:23 main smbd[1029]: [2022/01/08 00:06:23.794515, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 08 00:06:23 main systemd[1]: Started Samba SMB Daemon. Jan 08 00:06:23 main smbd[1029]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jan 08 00:06:23 main systemd[1]: Reached target Multi-User System. Jan 08 00:06:23 main systemd[1]: Reached target Graphical Interface. Jan 08 00:06:23 main systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 08 00:06:23 main systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 08 00:06:23 main systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 08 00:06:23 main systemd[1]: Startup finished in 9.962s (kernel) + 23.365s (userspace) = 33.327s. Jan 08 00:06:24 main startx[878]: .. Jan 08 00:06:24 main volumio[663]: info: touch_display: Setting screensaver timeout to 0 seconds. Jan 08 00:06:24 main volumio[1032]: .......++++ Jan 08 00:06:24 main volumio-remote-updater[454]: [2022-01-08 00:06:24] [connect] Successful connection Jan 08 00:06:24 main volumio-remote-updater[454]: [2022-01-08 00:06:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1641600384 101 Jan 08 00:06:24 main volumio[663]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 3 Jan 08 00:06:28 main volumio[663]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.179&uuid=975c5321fdc57312637f8d9c8323d7ad" http://updates.volumio.org/downloader-v1/track-device Jan 08 00:06:28 main volumio[663]: % Total % Received % Xferd Average Speed Time Time Time Current Jan 08 00:06:28 main volumio[663]: Dload Upload Total Spent Left Speed Jan 08 00:06:28 main volumio[663]: [132B blob data] Jan 08 00:06:28 main volumio[663]: retrying in 5 seconds, trial 0 Jan 08 00:06:28 main volumio[663]: info: Volumio Calling Home Jan 08 00:06:32 main volumio[1032]: ....................................................................................++++ Jan 08 00:06:32 main volumio[1032]: e is 65537 (0x010001) Jan 08 00:06:32 main volumio[1032]: writing RSA key Jan 08 00:06:32 main volumio[663]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Total Clients: 4 Jan 08 00:06:33 main volumio[663]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Total Clients: 5 Jan 08 00:06:34 main volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources Jan 08 00:06:34 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:06:34 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:06:34 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:34 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 08 00:06:34 main volumio[663]: info: Listing playlists Jan 08 00:06:34 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 08 00:06:34 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 08 00:06:34 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 08 00:06:34 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 08 00:06:34 main systemd[1]: systemd-fsckd.service: Succeeded. Jan 08 00:06:35 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:06:39 main volumio[663]: error: MyVolumio Plugin failed to start in a timely fashion Jan 08 00:06:39 main volumio[663]: info: BOOT COMPLETED Jan 08 00:06:39 main volumio[663]: [Metrics] CommandRouter: 27s 956.18ms Jan 08 00:06:39 main volumio[663]: info: CoreCommandRouter::volumiosetStartupVolume Jan 08 00:06:39 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:06:39 main volumio[663]: info: VolumeController:: Setting startup Volume 100 Jan 08 00:06:39 main volumio[663]: info: VolumeController::SetAlsaVolume100 Jan 08 00:06:39 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:06:39 main volumio[663]: info: CoreCommandRouter::Close All Modals sent Jan 08 00:06:39 main volumio[663]: info: CoreCommandRouter::Close All Modals sent Jan 08 00:06:39 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:06:39 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:39 main volumio[663]: info: CoreStateMachine::pushState Jan 08 00:06:39 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:06:39 main volumio[663]: info: CoreCommandRouter::volumioPushState Jan 08 00:06:39 main volumio[663]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Jan 08 00:06:39 main volumio[663]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:1413:(_snd_pcm_volumioswitch_open) Failed to open control fifo Jan 08 00:06:39 main volumio[663]: aplay: main:828: audio open error: No such file or directory Jan 08 00:06:40 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 08 00:06:40 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 08 00:06:40 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 08 00:06:43 main systemd[1]: systemd-hostnamed.service: Succeeded. Jan 08 00:06:48 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 00:06:48 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:06:58 main volumio[663]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.179&uuid=975c5321fdc57312637f8d9c8323d7ad" http://updates.volumio.org/downloader-v1/track-device Jan 08 00:06:58 main volumio[663]: % Total % Received % Xferd Average Speed Time Time Time Current Jan 08 00:06:58 main volumio[663]: Dload Upload Total Spent Left Speed Jan 08 00:06:58 main volumio[663]: [1.6K blob data] Jan 08 00:06:58 main volumio[663]: retrying in 5 seconds, trial 1 Jan 08 00:06:58 main volumio[663]: info: Volumio Calling Home Jan 08 00:07:02 main volumio[663]: info: Discovery: adding d55e7ab3-30dd-4341-82d1-2250a89c24ef Jan 08 00:07:02 main volumio[663]: info: mDNS: Found device Main Jan 08 00:07:02 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:07:02 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:07:29 main volumio[663]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.179&uuid=975c5321fdc57312637f8d9c8323d7ad" http://updates.volumio.org/downloader-v1/track-device Jan 08 00:07:29 main volumio[663]: % Total % Received % Xferd Average Speed Time Time Time Current Jan 08 00:07:29 main volumio[663]: Dload Upload Total Spent Left Speed Jan 08 00:07:29 main volumio[663]: [1.6K blob data] Jan 08 00:07:29 main volumio[663]: retrying in 5 seconds, trial 2 Jan 08 00:07:29 main volumio[663]: info: Volumio Calling Home Jan 08 00:07:35 main ntpd[638]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jan 08 00:07:55 main ntpd[638]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jan 08 00:08:03 main volumio[663]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Total Clients: 5 Jan 08 00:08:03 main volumio[663]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Total Clients: 5 Jan 08 00:08:03 main volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources Jan 08 00:08:03 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:08:03 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:08:03 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:08:03 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 08 00:08:03 main volumio[663]: info: Listing playlists Jan 08 00:08:04 main volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources Jan 08 00:08:04 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:08:04 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:08:04 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:08:04 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 08 00:08:04 main volumio[663]: info: Listing playlists Jan 08 00:08:14 main dhcpcd[960]: eth0: offered 192.168.1.135 from 192.168.1.254 Jan 08 00:08:14 main dhcpcd[960]: eth0: probing address 192.168.1.135/24 Jan 08 00:08:15 main ntpd[638]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jan 08 00:08:19 main dhcpcd[960]: eth0: leased 192.168.1.135 for 86400 seconds Jan 08 00:08:19 main dhcpcd[960]: eth0: adding route to 192.168.1.0/24 Jan 08 00:08:19 main avahi-daemon[459]: Registering new address record for 192.168.1.135 on eth0.IPv4. Jan 08 00:08:19 main dhcpcd[960]: eth0: changing default route via 192.168.1.254 Jan 08 00:08:19 main dhcpcd[960]: eth0: deleting route to 169.254.0.0/16 Jan 08 00:08:19 main avahi-daemon[459]: Withdrawing address record for 169.254.193.92 on eth0. Jan 08 00:08:19 main avahi-daemon[459]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.193.92. Jan 08 00:08:19 main avahi-daemon[459]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.135. Jan 08 00:08:19 main dhcpcd[960]: eth0: pid 960 deleted default route via 192.168.1.254 Jan 08 00:08:20 main ntpd[638]: Listen normally on 4 eth0 192.168.1.135:123 Jan 08 00:08:20 main ntpd[638]: Deleting interface #3 eth0, 169.254.193.92#123, interface stats: received=0, sent=0, dropped=0, active_time=117 secs Jan 08 00:08:20 main ntpd[638]: new interface(s) found: waking up resolver Jan 08 00:08:20 main ntpd[638]: Soliciting pool server 168.61.215.74 Jan 08 00:08:20 main ntpd[638]: Soliciting pool server 193.150.22.36 Jan 08 00:08:20 main ntpd[638]: Soliciting pool server 216.229.0.49 Jan 08 00:08:21 main ntpd[638]: Soliciting pool server 108.59.2.24 Jan 08 00:08:21 main ntpd[638]: Soliciting pool server 178.62.18.76 Jan 08 00:08:21 main ntpd[638]: Soliciting pool server 44.190.6.254 Jan 08 00:08:22 main ntpd[638]: Soliciting pool server 45.15.168.96 Jan 08 00:08:22 main ntpd[638]: Soliciting pool server 62.101.228.30 Jan 08 00:08:22 main volumio[663]: info: mDNS Browse raised the following error Error: getaddrinfo -3007 Jan 08 00:08:22 main ntpd[638]: Soliciting pool server 162.159.200.1 Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 08 00:08:22 main volumio[663]: info: Adding plugin bluetooth to MyMusic Plugins Jan 08 00:08:22 main volumio[663]: info: Adding plugin multiroom to MyMusic Plugins Jan 08 00:08:22 main volumio[663]: info: Adding plugin cd_controller to MyMusic Plugins Jan 08 00:08:22 main volumio[663]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 08 00:08:22 main volumio[663]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 08 00:08:22 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 08 00:08:23 main ntpd[638]: Soliciting pool server 23.131.160.7 Jan 08 00:08:23 main ntpd[638]: Soliciting pool server 64.142.54.12 Jan 08 00:08:23 main ntpd[638]: Soliciting pool server 47.190.36.235 Jan 08 00:08:23 main volumio[663]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 08 00:08:23 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 08 00:08:23 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:08:23 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:08:23 main volumio[663]: info: Starting MyVolumio Remote Streaming Endpoints Jan 08 00:08:23 main volumio[663]: info: MyVolumio login type: Token Jan 08 00:08:23 main volumio[663]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 08 00:08:23 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 08 00:08:23 main volumio[663]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 08 00:08:23 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 08 00:08:23 main volumio[663]: info: Streaming services startup Jan 08 00:08:23 main volumio[663]: info: Starting Streaming Daemon Jan 08 00:08:23 main sudo[1563]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 08 00:08:23 main sudo[1563]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:08:23 main systemd[1]: Stopping Volumio Streaming Daemon... Jan 08 00:08:23 main systemd[1]: volumio-streaming-daemon.service: Main process exited, code=killed, status=15/TERM Jan 08 00:08:23 main systemd[1]: volumio-streaming-daemon.service: Succeeded. Jan 08 00:08:23 main systemd[1]: Stopped Volumio Streaming Daemon. Jan 08 00:08:23 main systemd[1]: Started Volumio Streaming Daemon. Jan 08 00:08:23 main sudo[1563]: pam_unix(sudo:session): session closed for user root Jan 08 00:08:23 main volumio-streaming-daemon[1569]: ############################ Jan 08 00:08:23 main volumio-streaming-daemon[1569]: # Volumio Streaming Daemon # Jan 08 00:08:23 main volumio-streaming-daemon[1569]: # Running on port 7777 # Jan 08 00:08:23 main volumio-streaming-daemon[1569]: ############################ Jan 08 00:08:23 main volumio-streaming-daemon[1569]: Environment: production Jan 08 00:08:23 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 08 00:08:23 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 08 00:08:23 main volumio[663]: info: Discovery: Getting this device information Jan 08 00:08:23 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:08:23 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:08:23 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 08 00:08:23 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:08:24 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 5 Jan 08 00:08:24 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:08:24 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:08:24 main volumio[663]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 08 00:08:24 main volumio[663]: info: MYVOLUMIO: Adding device Jan 08 00:08:24 main volumio[663]: info: MYVOLUMIO: Evaluating Server Jan 08 00:08:24 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jan 08 00:08:24 main volumio[663]: info: MyVolumio login type: Token Jan 08 00:08:24 main ntpd[638]: Soliciting pool server 45.83.234.123 Jan 08 00:08:24 main ntpd[638]: Soliciting pool server 2600:3c01::f03c:91ff:fe96:13c5 Jan 08 00:08:24 main volumio[663]: info: [MyVolumio PluginManager] Subscribed plan changed to superstar Jan 08 00:08:24 main volumio[663]: info: Adding audio output: Jan 08 00:08:24 main volumio[663]: info: MYVOLUMIO: Adding device Jan 08 00:08:24 main volumio[663]: info: MYVOLUMIO: Evaluating Server Jan 08 00:08:24 main volumio[663]: info: Remote config written successfully Jan 08 00:08:24 main volumio[663]: info: Starting Tunnel 1 Jan 08 00:08:24 main volumio[663]: info: Starting Tunnel Connection Checker Jan 08 00:08:24 main volumio[663]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Jan 08 00:08:24 main volumio[663]: info: MyVolumio status changed Jan 08 00:08:24 main volumio[663]: info: Streaming services startup Jan 08 00:08:24 main volumio[663]: info: Re-Starting Streaming Daemon Jan 08 00:08:24 main volumio-streaming-daemon[1569]: Restarting daemon Jan 08 00:08:24 main volumio-streaming-daemon[1569]: Environment: production Jan 08 00:08:24 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Jan 08 00:08:24 main sudo[1598]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Jan 08 00:08:24 main sudo[1598]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:08:24 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Jan 08 00:08:24 main systemd[1]: Started MyVolumio SSH Tunnel. Jan 08 00:08:24 main sudo[1598]: pam_unix(sudo:session): session closed for user root Jan 08 00:08:24 main autossh[1601]: port set to 0, monitoring disabled Jan 08 00:08:24 main autossh[1601]: starting ssh (count 1) Jan 08 00:08:24 main autossh[1601]: ssh child pid is 1604 Jan 08 00:08:25 main volumio[663]: info: [1641600505005] Starting BluetoothController Jan 08 00:08:25 main volumio-streaming-daemon[1569]: Enabled services: Jan 08 00:08:25 main volumio-streaming-daemon[1569]: 1) tidal Jan 08 00:08:25 main volumio-streaming-daemon[1569]: 2) qobuz Jan 08 00:08:25 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Jan 08 00:08:25 main ntpd[638]: Soliciting pool server 50.205.244.108 Jan 08 00:08:26 main volumio[663]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Jan 08 00:08:26 main sudo[1607]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /myvolumio/plugins/audio_interface/multiroom/scripts/check_snapcast Jan 08 00:08:26 main sudo[1607]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:08:26 main sudo[1607]: pam_unix(sudo:session): session closed for user root Jan 08 00:08:26 main sudo[1610]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Jan 08 00:08:26 main sudo[1610]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:08:26 main sudo[1610]: pam_unix(sudo:session): session closed for user root Jan 08 00:08:26 main volumio[663]: info: MultiRoom plugin initialized Jan 08 00:08:26 main volumio[663]: STOPPING SNAPCLIENT Jan 08 00:08:26 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Jan 08 00:08:26 main sudo[1626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Jan 08 00:08:26 main sudo[1626]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:08:26 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Jan 08 00:08:26 main sudo[1626]: pam_unix(sudo:session): session closed for user root Jan 08 00:08:26 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Jan 08 00:08:26 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Jan 08 00:08:26 main volumio[663]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Jan 08 00:08:26 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Jan 08 00:08:26 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Jan 08 00:08:26 main volumio[663]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Jan 08 00:08:26 main volumio[663]: info: Preparing to generate the ALSA configuration file Jan 08 00:08:26 main volumio[663]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 08 00:08:26 main volumio[663]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 08 00:08:26 main volumio[663]: info: Reading ALSA contributions from plugins. Jan 08 00:08:26 main volumio[663]: info: Setting Geolocation for MyVolumio to us1 Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:08:26 main volumio[663]: info: Setting Geolocation for MyVolumio to us1 Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:08:26 main volumio[663]: info: MRS: SNAPCLIENT STOPPED Jan 08 00:08:26 main volumio[663]: info: Snap server and client installed Jan 08 00:08:26 main volumio[663]: info: Remote SSH Started Jan 08 00:08:26 main volumio[663]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Jan 08 00:08:26 main volumio[663]: info: Asound.conf file unchanged, so no further update is needed Jan 08 00:08:26 main volumio[663]: info: Output device has changed, restarting MPD Jan 08 00:08:26 main sudo[1629]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 08 00:08:26 main sudo[1629]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:08:26 main volumio[663]: info: Output device has changed, restarting Shairport Sync Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:08:26 main sudo[1629]: pam_unix(sudo:session): session closed for user root Jan 08 00:08:26 main sudo[1632]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 08 00:08:26 main sudo[1632]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:08:26 main systemd[1]: Stopping Music Player Daemon... Jan 08 00:08:26 main volumio[663]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 08 00:08:26 main volumio[663]: [SpotifyConnect] Creating VLS config file Jan 08 00:08:26 main systemd[1]: mpd.service: Succeeded. Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:08:26 main systemd[1]: Stopped Music Player Daemon. Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:08:26 main volumio[663]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 08 00:08:26 main systemd[1]: Starting Music Player Daemon... Jan 08 00:08:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:08:27 main volumio[663]: info: MPD Permissions set Jan 08 00:08:27 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:08:27 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:08:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:08:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:08:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:08:27 main volumio[663]: info: Starting Shairport Sync Jan 08 00:08:27 main volumio[663]: [SpotifyConnect] Restarting Vollibrespot Daemon Jan 08 00:08:27 main sudo[1647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 08 00:08:27 main sudo[1647]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:08:27 main volumio-streaming-daemon[1569]: Environment: production Jan 08 00:08:27 main systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 08 00:08:27 main systemd[1]: shairport-sync.service: Succeeded. Jan 08 00:08:27 main systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 08 00:08:27 main systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 08 00:08:27 main sudo[1650]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service Jan 08 00:08:27 main sudo[1650]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:08:27 main sudo[1647]: pam_unix(sudo:session): session closed for user root Jan 08 00:08:27 main systemd[1]: Stopping Volspotconnect2 Daemon... Jan 08 00:08:27 main systemd[1]: volspotconnect2.service: Main process exited, code=killed, status=15/TERM Jan 08 00:08:27 main systemd[1]: volspotconnect2.service: Succeeded. Jan 08 00:08:27 main systemd[1]: Stopped Volspotconnect2 Daemon. Jan 08 00:08:27 main volumio[663]: Current plan: superstar. Enabling manifest UI Jan 08 00:08:27 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Jan 08 00:08:27 main systemd[1]: Started Volspotconnect2 Daemon. Jan 08 00:08:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 08 00:08:27 main sudo[1650]: pam_unix(sudo:session): session closed for user root Jan 08 00:08:27 main volumio[1656]: vollibrespot v0.2.3 769ce77 2021-06-04 (librespot 08d8bcc 2020-10-07) -- Built On 2021-06-04 Jan 08 00:08:27 main volumio[1656]: Reading Config from "volspotify.toml" Jan 08 00:08:27 main volumio[1656]: [Vollibrespot] : Using Alsa backend with device: volumio Jan 08 00:08:27 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Jan 08 00:08:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Jan 08 00:08:27 main volumio[663]: info: MRS: Pushing multiroomSync output for this device Jan 08 00:08:27 main volumio[663]: info: MRS: Pushing multiroomSync output Jan 08 00:08:27 main volumio[663]: info: Adding audio output: Jan 08 00:08:27 main volumio[663]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 08 00:08:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 08 00:08:27 main sudo[1659]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Main Jan 08 00:08:27 main volumio[1656]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } Jan 08 00:08:27 main sudo[1659]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:08:27 main sudo[1659]: pam_unix(sudo:session): session closed for user root Jan 08 00:08:27 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Jan 08 00:08:27 main volumio[663]: info: Adding METAVOLUMIO REST API Endpoints Jan 08 00:08:27 main volumio[663]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Jan 08 00:08:27 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Jan 08 00:08:27 main volumio[663]: info: Preparing CD Folders Jan 08 00:08:27 main volumio[663]: info: Adding CD REST API Endpoints Jan 08 00:08:27 main volumio[663]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Jan 08 00:08:27 main volumio[663]: info: Starting UDEV Watcher for CD Jan 08 00:08:27 main volumio[663]: info: Detecting CD presence with UDEV Jan 08 00:08:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Jan 08 00:09:17 main ntpd[638]: receive: Unexpected origin timestamp 0xe583547b.804da901 does not match aorg 0000000000.00000000 from server@178.62.18.76 xmt 0xe58354ad.39240294 Jan 08 00:09:17 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Jan 08 00:09:17 main volumio[663]: info: Adding inputs REST Endpoints Jan 08 00:09:17 main volumio[663]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Jan 08 00:09:17 main volumio[663]: info: Scanning Audio Inputs Jan 08 00:09:17 main ntpd[638]: receive: Unexpected origin timestamp 0xe583547b.804925ff does not match aorg 0000000000.00000000 from server@62.101.228.30 xmt 0xe58354ad.3d63342e Jan 08 00:09:17 main volumio[663]: info: Checking against Known Cards name Jan 08 00:09:17 main volumio[663]: info: Adding Server instance for streaming Jan 08 00:09:17 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Jan 08 00:09:17 main volumio[663]: error: Hi Res Audio Failed Login: Missing Login Data Jan 08 00:09:17 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Jan 08 00:09:17 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Jan 08 00:09:17 main volumio[663]: info: Refreshing QOBUZ token Jan 08 00:09:17 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Jan 08 00:09:17 main volumio[663]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Jan 08 00:09:17 main volumio[663]: info: Stopping AccessToken refresher cron Jan 08 00:09:17 main volumio[663]: info: AccessToken refresher cron started Jan 08 00:09:17 main volumio[663]: info: Shairport-Sync Started Jan 08 00:09:17 main volumio[663]: info: Updating MyVolumio device info Jan 08 00:09:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:09:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:09:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:09:17 main volumio[663]: info: Updating MyVolumio device info Jan 08 00:09:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:09:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:09:17 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 08 00:09:17 main mpd[1645]: Jan 08 00:09 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 08 00:09:17 main mpd[1645]: Jan 08 00:09 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jan 08 00:09:17 main mpd[1645]: Jan 08 00:09 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jan 08 00:09:17 main systemd[1]: Started Music Player Daemon. Jan 08 00:09:17 main sudo[1632]: pam_unix(sudo:session): session closed for user root Jan 08 00:09:17 main volumio[663]: info: Bluetooth name changed to Main Jan 08 00:09:17 main volumio[663]: [SpotifyConnect] Vollibrespot Daemon service restarted! Jan 08 00:09:17 main volumio-streaming-daemon[1569]: Environment: production Jan 08 00:09:17 main volumio-streaming-daemon[1569]: Environment: production Jan 08 00:09:17 main volumio[663]: info: Fetching Streaming Services browse cache Jan 08 00:09:17 main volumio[663]: error: updateQueue error: null Jan 08 00:09:17 main volumio[663]: warn: QOBUZ login failed: No access token received Jan 08 00:09:17 main volumio[663]: info: Stopping AccessToken refresher cron for QOBUZ Jan 08 00:09:17 main volumio[663]: info: AccessToken refresher cron started for QOBUZ Jan 08 00:09:17 main volumio[663]: info: Fetching Streaming Services browse cache Jan 08 00:09:19 main sudo[1670]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Jan 08 00:09:19 main sudo[1670]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:09:19 main systemd[1]: Started Volumio Bluetooth Module. Jan 08 00:09:20 main sudo[1670]: pam_unix(sudo:session): session closed for user root Jan 08 00:09:20 main sudo[1673]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Jan 08 00:09:20 main volumio[663]: info: Volumio BT Module successfully started Jan 08 00:09:20 main sudo[1673]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:09:20 main volumiobt[1672]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Jan 08 00:09:20 main sudo[1673]: pam_unix(sudo:session): session closed for user root Jan 08 00:09:21 main sudo[1677]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Jan 08 00:09:21 main sudo[1677]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:09:21 main volumiobt[1672]: pulseaudio: no process found Jan 08 00:09:21 main sudo[1677]: pam_unix(sudo:session): session closed for user root Jan 08 00:09:21 main dbus-daemon[447]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.27' (uid=1000 pid=1681 comm="/usr/bin/pulseaudio ") Jan 08 00:09:21 main systemd[1]: Starting RealtimeKit Scheduling Policy Service... Jan 08 00:09:21 main volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 08 00:09:21 main volumio[663]: BT PLUGIN MESSAGE: Playing: false Jan 08 00:09:21 main volumio[663]: BT PLUGIN MESSAGE: VOLATILE: Jan 08 00:09:21 main volumio[663]: BT PLUGIN MESSAGE: STATE:undefined Jan 08 00:09:21 main dbus-daemon[447]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Jan 08 00:09:21 main systemd[1]: Started RealtimeKit Scheduling Policy Service. Jan 08 00:09:21 main rtkit-daemon[1682]: Successfully called chroot. Jan 08 00:09:21 main rtkit-daemon[1682]: Successfully dropped privileges. Jan 08 00:09:21 main rtkit-daemon[1682]: Successfully limited resources. Jan 08 00:09:21 main rtkit-daemon[1682]: Running. Jan 08 00:09:21 main rtkit-daemon[1682]: Watchdog thread running. Jan 08 00:09:21 main rtkit-daemon[1682]: Canary thread running. Jan 08 00:09:21 main dbus-daemon[447]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.28' (uid=0 pid=1682 comm="/usr/lib/rtkit/rtkit-daemon ") Jan 08 00:09:21 main systemd[1]: Starting Authorization Manager... Jan 08 00:09:21 main volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 08 00:09:21 main volumio[663]: BT PLUGIN MESSAGE: Playing: false Jan 08 00:09:21 main volumio[663]: BT PLUGIN MESSAGE: VOLATILE: Jan 08 00:09:21 main volumio[663]: BT PLUGIN MESSAGE: STATE:undefined Jan 08 00:09:21 main polkitd[1685]: started daemon version 0.105 using authority implementation `local' version `0.105' Jan 08 00:09:21 main dbus-daemon[447]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Jan 08 00:09:21 main systemd[1]: Started Authorization Manager. Jan 08 00:09:21 main pulseaudio[1681]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jan 08 00:09:21 main pulseaudio[1681]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jan 08 00:09:21 main bluetoothd[711]: Endpoint registered: sender=:1.48 path=/MediaEndpoint/A2DPSource Jan 08 00:09:21 main bluetoothd[711]: Endpoint registered: sender=:1.48 path=/MediaEndpoint/A2DPSink Jan 08 00:09:21 main volumiobt[1672]: Applying permissions Jan 08 00:09:21 main volumiobt[1672]: Setting BT discoverable and pairable Jan 08 00:09:21 main pulseaudio[1681]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Jan 08 00:09:21 main kernel: Bluetooth: RFCOMM TTY layer initialized Jan 08 00:09:21 main kernel: Bluetooth: RFCOMM socket layer initialized Jan 08 00:09:21 main kernel: Bluetooth: RFCOMM ver 1.11 Jan 08 00:09:21 main volumiobt[1672]: Agent registered Jan 08 00:09:21 main volumiobt[1672]: [bluetooth]# -e power on Jan 08 00:09:21 main volumiobt[1672]: Invalid command in menu main: -e Jan 08 00:09:21 main volumiobt[1672]: Jan 08 00:09:21 main volumiobt[1672]: Use "help" for a list of available commands in a menu. Jan 08 00:09:21 main volumiobt[1672]: Use "menu " if you want to enter any submenu. Jan 08 00:09:21 main volumiobt[1672]: Use "back" if you want to return to menu main. Jan 08 00:09:21 main volumiobt[1672]: [bluetooth]# agent on Jan 08 00:09:21 main volumiobt[1672]: Agent is already registered Jan 08 00:09:21 main volumiobt[1672]: [bluetooth]# discoverable on Jan 08 00:09:21 main volumiobt[1672]: [bluetooth]# pairable on Jan 08 00:09:21 main volumiobt[1672]: [bluetooth]# agent NoInputNoOutput Jan 08 00:09:21 main volumiobt[1672]: Agent is already registered Jan 08 00:09:21 main volumiobt[1672]: [bluetooth]# default-agent Jan 08 00:09:21 main volumiobt[1672]: [bluetooth]# quit Jan 08 00:09:21 main volumiobt[1672]: [59B blob data] Jan 08 00:09:21 main volumio[663]: info: MRS: Getting audio outputs on start Jan 08 00:09:21 main volumio[663]: info: MRS: Requesting all other devices output Jan 08 00:09:25 main sudo[1697]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:09:25 main sudo[1697]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:09:25 main sudo[1697]: pam_unix(sudo:session): session closed for user root Jan 08 00:09:25 main sudo[1699]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:09:25 main sudo[1699]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:09:25 main sudo[1699]: pam_unix(sudo:session): session closed for user root Jan 08 00:09:25 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 7 Jan 08 00:09:25 main volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources Jan 08 00:09:25 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:09:25 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:09:25 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:09:25 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 08 00:09:25 main volumio[663]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 08 00:09:26 main volumio[663]: info: Listing playlists Jan 08 00:09:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 08 00:09:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 08 00:09:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 08 00:09:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 08 00:09:27 main volumio[663]: info: CoreCommandRouter::volumioGetQueue Jan 08 00:09:27 main volumio[663]: info: CoreStateMachine::getQueue Jan 08 00:09:27 main volumio[663]: info: CorePlayQueue::getQueue Jan 08 00:09:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:09:28 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:09:30 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:09:30 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 08 00:09:30 main volumio[663]: info: Received Get System Version Jan 08 00:09:30 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 08 00:09:33 main volumio-remote-updater[454]: No test mode Jan 08 00:09:33 main volumio-remote-updater[454]: No alpha test mode Jan 08 00:09:33 main volumio[663]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 08 00:09:34 main volumio[663]: info: CoreCommandRouter::Close All Modals sent Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:09:43 main volumio[663]: info: Retrieving Cloud Streaming UI Jan 08 00:09:43 main volumio[663]: info: Getting Tidal Cloud Configuration Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:09:43 main volumio[663]: info: Getting Qobuz Cloud Configuration Jan 08 00:09:43 main volumio[663]: info: Asking plugin for UI Config Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:09:43 main volumio[663]: info: Getting Spotify Cloud Configuration Jan 08 00:09:43 main volumio[663]: info: Asking plugin for UI Config Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:09:43 main volumio[663]: info: Saving Spotify Acccount Jan 08 00:09:43 main volumio[663]: info: Got it Jan 08 00:09:43 main volumio[663]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jan 08 00:09:43 main volumio[663]: info: Got Tidal Cloud Configuration Jan 08 00:09:43 main volumio[663]: info: Got it Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::volumioGetBrowseSources Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 08 00:09:43 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 08 00:09:47 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 08 00:10:06 main sudo[1714]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:10:06 main sudo[1714]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:10:06 main sudo[1714]: pam_unix(sudo:session): session closed for user root Jan 08 00:10:06 main sudo[1717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:10:06 main sudo[1717]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:10:06 main sudo[1717]: pam_unix(sudo:session): session closed for user root Jan 08 00:10:06 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 7 Jan 08 00:10:07 main volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources Jan 08 00:10:07 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:10:07 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:10:07 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:10:07 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 08 00:10:07 main volumio[663]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 08 00:10:07 main volumio[663]: info: Listing playlists Jan 08 00:10:07 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 08 00:10:07 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 08 00:10:07 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 08 00:10:07 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 08 00:10:08 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 08 00:10:08 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 08 00:10:08 main volumio[663]: info: Discovery: Getting this device information Jan 08 00:10:08 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:10:08 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:10:08 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 08 00:10:08 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:10:09 main sudo[1724]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:10:09 main sudo[1724]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:10:09 main sudo[1724]: pam_unix(sudo:session): session closed for user root Jan 08 00:10:09 main sudo[1727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:10:09 main sudo[1727]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:10:09 main sudo[1727]: pam_unix(sudo:session): session closed for user root Jan 08 00:10:09 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 8 Jan 08 00:10:09 main volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources Jan 08 00:10:09 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:10:09 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:10:09 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:10:09 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 08 00:10:09 main volumio[663]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 08 00:10:09 main volumio[663]: info: Listing playlists Jan 08 00:10:09 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:10:11 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:10:16 main sudo[1732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:10:16 main sudo[1732]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:10:16 main sudo[1732]: pam_unix(sudo:session): session closed for user root Jan 08 00:10:16 main sudo[1735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:10:16 main sudo[1735]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:10:16 main sudo[1735]: pam_unix(sudo:session): session closed for user root Jan 08 00:10:16 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 8 Jan 08 00:10:16 main volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources Jan 08 00:10:16 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:10:16 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:10:16 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:10:16 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 08 00:10:16 main volumio[663]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 08 00:10:16 main volumio[663]: info: Listing playlists Jan 08 00:10:18 main volumio[663]: info: CoreCommandRouter::volumioGetQueue Jan 08 00:10:18 main volumio[663]: info: CoreStateMachine::getQueue Jan 08 00:10:18 main volumio[663]: info: CorePlayQueue::getQueue Jan 08 00:10:31 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 6 Jan 08 00:10:31 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:10:31 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:10:33 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 08 00:10:33 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 08 00:10:33 main volumio[663]: info: Discovery: Getting this device information Jan 08 00:10:33 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:10:33 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:10:33 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 08 00:11:24 main volumiossh-tunnel[1600]: ssh: connect to host eu1.myvolumio.org port 2222: Connection timed out Jan 08 00:11:24 main autossh[1601]: ssh exited with error status 255; restarting ssh Jan 08 00:11:24 main autossh[1601]: starting ssh (count 2) Jan 08 00:11:24 main autossh[1601]: ssh child pid is 1743 Jan 08 00:13:14 main volumio[663]: info: Tunnel connection is inactive, restarting it Jan 08 00:13:14 main volumio[663]: info: Starting Tunnel 1 Jan 08 00:13:14 main volumio[663]: info: Starting Tunnel Connection Checker Jan 08 00:13:14 main sudo[1762]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Jan 08 00:13:14 main sudo[1762]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:13:14 main autossh[1601]: received signal to exit (15) Jan 08 00:13:14 main systemd[1]: Stopping MyVolumio SSH Tunnel... Jan 08 00:13:14 main systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Jan 08 00:13:14 main systemd[1]: sshtunnel.service: Succeeded. Jan 08 00:13:14 main systemd[1]: Stopped MyVolumio SSH Tunnel. Jan 08 00:13:14 main volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 08 00:13:14 main volumio[663]: BT PLUGIN MESSAGE: Playing: false Jan 08 00:13:14 main systemd[1]: Started MyVolumio SSH Tunnel. Jan 08 00:13:14 main volumio[663]: BT PLUGIN MESSAGE: VOLATILE: Jan 08 00:13:14 main volumio[663]: BT PLUGIN MESSAGE: STATE:undefined Jan 08 00:13:14 main volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jan 08 00:13:14 main volumio[663]: BT PLUGIN MESSAGE: Playing: false Jan 08 00:13:14 main volumio[663]: BT PLUGIN MESSAGE: VOLATILE: Jan 08 00:13:14 main volumio[663]: BT PLUGIN MESSAGE: STATE:undefined Jan 08 00:13:14 main sudo[1762]: pam_unix(sudo:session): session closed for user root Jan 08 00:13:14 main autossh[1765]: port set to 0, monitoring disabled Jan 08 00:13:14 main autossh[1765]: starting ssh (count 1) Jan 08 00:13:14 main autossh[1765]: ssh child pid is 1768 Jan 08 00:13:14 main volumio[663]: info: Remote SSH Started Jan 08 00:13:14 main volumio[663]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Jan 08 00:13:14 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:13:14 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:13:14 main volumiossh-tunnel[1764]: Warning: Permanently added '[us1.myvolumio.org]:2222,[162.243.167.188]:2222' (RSA) to the list of known hosts. Jan 08 00:14:24 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 6 Jan 08 00:14:24 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:14:24 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:14:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 08 00:14:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 08 00:14:26 main volumio[663]: info: Discovery: Getting this device information Jan 08 00:14:26 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:14:26 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:14:26 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 08 00:14:26 main sudo[1775]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:14:26 main sudo[1775]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:14:26 main sudo[1775]: pam_unix(sudo:session): session closed for user root Jan 08 00:14:26 main sudo[1778]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:14:26 main sudo[1778]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:14:26 main sudo[1778]: pam_unix(sudo:session): session closed for user root Jan 08 00:14:26 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 7 Jan 08 00:14:27 main volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources Jan 08 00:14:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:14:27 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:14:27 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:14:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 08 00:14:27 main volumio[663]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 08 00:14:27 main volumio[663]: info: Listing playlists Jan 08 00:14:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 08 00:14:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 08 00:14:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 08 00:14:27 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 08 00:14:28 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:14:29 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:14:31 main volumio[663]: info: Retrieving Cloud Streaming UI Jan 08 00:14:31 main volumio[663]: info: Getting Tidal Cloud Configuration Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:14:31 main volumio[663]: info: Getting Qobuz Cloud Configuration Jan 08 00:14:31 main volumio[663]: info: Asking plugin for UI Config Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:14:31 main volumio[663]: info: Getting Spotify Cloud Configuration Jan 08 00:14:31 main volumio[663]: info: Asking plugin for UI Config Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:14:31 main volumio[663]: info: Saving Spotify Acccount Jan 08 00:14:31 main volumio[663]: info: Got it Jan 08 00:14:31 main volumio[663]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jan 08 00:14:31 main volumio[663]: info: Got Tidal Cloud Configuration Jan 08 00:14:31 main volumio[663]: info: Got it Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::volumioGetBrowseSources Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 08 00:14:31 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 08 00:14:32 main volumio[663]: info: Disabling MyMusic plugin upnp_browser Jan 08 00:14:32 main volumio[663]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesMedia Servers Jan 08 00:14:32 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:14:32 main volumio[663]: info: Disabling plugin upnp_browser Jan 08 00:14:32 main volumio[663]: info: Done. Jan 08 00:14:46 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 6 Jan 08 00:14:46 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:14:46 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:14:48 main sudo[1787]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:14:48 main sudo[1787]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:14:48 main sudo[1787]: pam_unix(sudo:session): session closed for user root Jan 08 00:14:48 main sudo[1790]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:14:48 main sudo[1790]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:14:48 main sudo[1790]: pam_unix(sudo:session): session closed for user root Jan 08 00:14:48 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 7 Jan 08 00:14:48 main volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources Jan 08 00:14:48 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:14:48 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:14:48 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:14:48 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 08 00:14:48 main volumio[663]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 08 00:14:48 main volumio[663]: info: Listing playlists Jan 08 00:14:48 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 08 00:14:48 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 08 00:14:48 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 08 00:14:48 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 08 00:14:50 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:14:50 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 08 00:14:50 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 08 00:14:50 main volumio[663]: info: Discovery: Getting this device information Jan 08 00:14:50 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:14:50 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:14:50 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 08 00:14:51 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:19:25 main ntpd[638]: 62.101.228.30 local addr 192.168.1.135 -> Jan 08 00:21:12 main ntpd[638]: 108.59.2.24 local addr 192.168.1.135 -> Jan 08 00:21:38 main ntpd[638]: 64.142.54.12 local addr 192.168.1.135 -> Jan 08 00:21:41 main systemd[1]: Starting Cleanup of Temporary Directories... Jan 08 00:21:41 main volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running Jan 08 00:21:41 main volumio[663]: BT PLUGIN MESSAGE: Playing: false Jan 08 00:21:41 main volumio[663]: BT PLUGIN MESSAGE: VOLATILE: Jan 08 00:21:41 main volumio[663]: BT PLUGIN MESSAGE: STATE:undefined Jan 08 00:21:41 main systemd[1]: systemd-tmpfiles-clean.service: Succeeded. Jan 08 00:21:41 main systemd[1]: Started Cleanup of Temporary Directories. Jan 08 00:22:11 main ntpd[638]: 45.15.168.96 local addr 192.168.1.135 -> Jan 08 00:22:40 main ntpd[638]: 193.150.22.36 local addr 192.168.1.135 -> Jan 08 00:22:52 main ntpd[638]: 45.83.234.123 local addr 192.168.1.135 -> Jan 08 00:24:17 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: okhttp/3.12.12 Total Clients: 7 Jan 08 00:24:17 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:24:17 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:24:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 08 00:24:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 08 00:24:18 main volumio[663]: info: Discovery: Getting this device information Jan 08 00:24:18 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:24:18 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:24:18 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 08 00:24:27 main ntpd[638]: 168.61.215.74 local addr 192.168.1.135 -> Jan 08 00:24:48 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:24:48 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 08 00:24:49 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jan 08 00:24:49 main sudo[1853]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jan 08 00:24:49 main sudo[1853]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:24:49 main sudo[1853]: pam_unix(sudo:session): session closed for user root Jan 08 00:24:49 main sudo[1859]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 08 00:24:49 main sudo[1859]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:24:49 main sudo[1859]: pam_unix(sudo:session): session closed for user root Jan 08 00:24:49 main sudo[1866]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 08 00:24:49 main sudo[1866]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:24:49 main sudo[1866]: pam_unix(sudo:session): session closed for user root Jan 08 00:24:49 main sudo[1872]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 08 00:24:49 main sudo[1872]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:24:49 main sudo[1872]: pam_unix(sudo:session): session closed for user root Jan 08 00:24:49 main sudo[1879]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:24:49 main sudo[1879]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:24:49 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Jan 08 00:24:49 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Jan 08 00:24:49 main sudo[1879]: pam_unix(sudo:session): session closed for user root Jan 08 00:24:49 main sudo[1881]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:24:49 main sudo[1881]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:24:49 main sudo[1881]: pam_unix(sudo:session): session closed for user root Jan 08 00:24:51 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 08 00:24:51 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 08 00:24:51 main volumio[663]: info: Discovery: Getting this device information Jan 08 00:24:51 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:24:51 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:24:51 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 08 00:25:20 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:25:20 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 08 00:25:20 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jan 08 00:25:20 main sudo[1889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jan 08 00:25:20 main sudo[1889]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:25:20 main sudo[1889]: pam_unix(sudo:session): session closed for user root Jan 08 00:25:20 main sudo[1895]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 08 00:25:20 main sudo[1895]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:25:20 main sudo[1895]: pam_unix(sudo:session): session closed for user root Jan 08 00:25:20 main sudo[1903]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 08 00:25:20 main sudo[1903]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:25:20 main sudo[1903]: pam_unix(sudo:session): session closed for user root Jan 08 00:25:20 main sudo[1909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 08 00:25:20 main sudo[1909]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:25:20 main sudo[1909]: pam_unix(sudo:session): session closed for user root Jan 08 00:25:20 main sudo[1914]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:25:20 main sudo[1914]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:25:20 main sudo[1914]: pam_unix(sudo:session): session closed for user root Jan 08 00:25:20 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Jan 08 00:25:20 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Jan 08 00:25:20 main sudo[1918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:25:20 main sudo[1918]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:25:20 main sudo[1918]: pam_unix(sudo:session): session closed for user root Jan 08 00:25:23 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 08 00:25:23 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 08 00:25:23 main volumio[663]: info: Discovery: Getting this device information Jan 08 00:25:23 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:25:23 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:25:23 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 08 00:25:39 main sudo[1923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:25:39 main sudo[1923]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:25:39 main sudo[1923]: pam_unix(sudo:session): session closed for user root Jan 08 00:25:39 main sudo[1926]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:25:39 main sudo[1926]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:25:39 main sudo[1926]: pam_unix(sudo:session): session closed for user root Jan 08 00:25:39 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: Mozilla/5.0 (Linux; Android 12; Pixel 3a) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.104 Mobile Safari/537.36 Total Clients: 8 Jan 08 00:25:40 main sudo[1930]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 08 00:25:40 main sudo[1930]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:25:40 main sudo[1930]: pam_unix(sudo:session): session closed for user root Jan 08 00:25:40 main sudo[1933]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 08 00:25:40 main sudo[1933]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:25:40 main sudo[1933]: pam_unix(sudo:session): session closed for user root Jan 08 00:25:40 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: Mozilla/5.0 (Linux; Android 12; Pixel 3a) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.104 Mobile Safari/537.36 Total Clients: 8 Jan 08 00:25:40 main volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources Jan 08 00:25:40 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:25:40 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:25:40 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:25:40 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 08 00:25:40 main volumio[663]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 08 00:25:40 main volumio[663]: info: Listing playlists Jan 08 00:25:40 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 08 00:25:40 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 08 00:25:40 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 08 00:25:40 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 08 00:25:42 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:25:42 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 08 00:25:42 main volumio[663]: info: CoreCommandRouter::volumioGetQueue Jan 08 00:25:42 main volumio[663]: info: CoreStateMachine::getQueue Jan 08 00:25:42 main volumio[663]: info: CorePlayQueue::getQueue Jan 08 00:25:44 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:25:47 main volumio[663]: info: Retrieving Cloud Streaming UI Jan 08 00:25:47 main volumio[663]: info: Getting Tidal Cloud Configuration Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:25:47 main volumio[663]: info: Getting Qobuz Cloud Configuration Jan 08 00:25:47 main volumio[663]: info: Asking plugin for UI Config Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:25:47 main volumio[663]: info: Getting Spotify Cloud Configuration Jan 08 00:25:47 main volumio[663]: info: Asking plugin for UI Config Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:25:47 main volumio[663]: info: Saving Spotify Acccount Jan 08 00:25:47 main volumio[663]: info: Got it Jan 08 00:25:47 main volumio[663]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jan 08 00:25:47 main volumio[663]: info: Got Tidal Cloud Configuration Jan 08 00:25:47 main volumio[663]: info: Got it Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::volumioGetBrowseSources Jan 08 00:25:47 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 08 00:25:48 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 08 00:25:50 main volumio[663]: info: Disabling MyMusic plugin smart_inputs Jan 08 00:25:50 main volumio[663]: info: [MyVolumio PluginManager] Disabling and stopping plugin music_service smart_inputs Jan 08 00:25:50 main volumio[663]: info: Removeing all smart Inputs Jan 08 00:25:50 main volumio[663]: info: Disabling plugin smart_inputs Jan 08 00:25:51 main volumio[663]: info: Enabling MyMusic plugin smart_inputs Jan 08 00:25:51 main volumio[663]: info: [MyVolumio PluginManager] Enabling and starting plugin music_service smart_inputs Jan 08 00:25:51 main volumio[663]: info: Enabling plugin smart_inputs Jan 08 00:25:51 main volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Jan 08 00:25:51 main volumio[663]: info: Adding inputs REST Endpoints Jan 08 00:25:51 main volumio[663]: info: Updating scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Jan 08 00:25:51 main volumio[663]: info: Scanning Audio Inputs Jan 08 00:25:51 main volumio[663]: info: Checking against Known Cards name Jan 08 00:25:51 main volumio[663]: info: Adding Server instance for streaming Jan 08 00:25:51 main volumio[663]: info: Done. Jan 08 00:25:51 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:25:51 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:25:51 main volumio[663]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jan 08 00:25:51 main volumio[663]: info: touch_display: Setting screensaver timeout to 0 seconds. Jan 08 00:25:51 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 08 00:25:53 main volumio[663]: info: Enabling MyMusic plugin upnp_browser Jan 08 00:25:53 main volumio[663]: info: Enabling plugin upnp_browser Jan 08 00:25:53 main volumio[663]: info: Loading plugin "upnp_browser"... Jan 08 00:25:53 main volumio[663]: info: PLUGIN START: upnp_browser Jan 08 00:25:53 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 08 00:25:53 main volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 08 00:25:53 main volumio[663]: info: [1641601553166] CoreMusicLibrary::Adding element Media Servers Jan 08 00:25:53 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 08 00:25:53 main volumio[663]: Cannot find translation for sourceMedia Servers Jan 08 00:25:53 main volumio[663]: info: Done. Jan 08 00:25:55 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 08 00:27:15 main volumio[663]: verbose: New Socket.io Connection to 192.168.1.135 from 192.168.1.80 UA: Mozilla/5.0 (Linux; Android 12; Pixel 3a) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.104 Mobile Safari/537.36 Total Clients: 7 Jan 08 00:27:15 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:27:15 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:27:15 main volumio[663]: info: CoreCommandRouter::volumioGetQueue Jan 08 00:27:15 main volumio[663]: info: CoreStateMachine::getQueue Jan 08 00:27:15 main volumio[663]: info: CorePlayQueue::getQueue Jan 08 00:27:15 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Jan 08 00:27:29 main volumio[663]: info: CALLMETHOD: system_controller system sendBugReport [object Object] Jan 08 00:27:29 main volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , sendBugReport Jan 08 00:27:29 main sudo[1976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig Jan 08 00:27:29 main sudo[1976]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 08 00:27:29 main sudo[1976]: pam_unix(sudo:session): session closed for user root Jan 08 00:27:30 main volumio[663]: info: CoreCommandRouter::volumioGetState Jan 08 00:27:30 main volumio[663]: info: CorePlayQueue::getTrack 0 Jan 08 00:27:30 main volumio[663]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jan 08 00:27:30 main volumio[663]: info: touch_display: Setting screensaver timeout to 0 seconds. Jan 08 00:27:34 main sudo[2025]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl -p 7 Jan 08 00:27:34 main sudo[2025]: pam_unix(sudo:session): session opened for user root by (uid=0)