May 22 02:06:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: wizard , connectWirelessNetwork May 22 02:06:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , getWiredInfo May 22 02:06:06 volumio sudo[2469]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 22 02:06:06 volumio sudo[2469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:06 volumio sudo[2469]: pam_unix(sudo:session): session closed for user root May 22 02:06:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings May 22 02:06:06 volumio volumio[1222]: info: Saving new wireless network May 22 02:06:06 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 22 02:06:06 volumio dbus-daemon[876]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.32' (uid=0 pid=2471 comm="timedatectl show --property=NTPSynchronized --valu") May 22 02:06:06 volumio sudo[2474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf May 22 02:06:06 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 22 02:06:06 volumio sudo[2474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:06 volumio dbus-daemon[876]: [system] Successfully activated service 'org.freedesktop.timedate1' May 22 02:06:06 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 22 02:06:06 volumio setdatetime-helper.sh[2468]: Time is already synchronized. May 22 02:06:06 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 22 02:06:06 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 22 02:06:10 volumio sudo[2474]: pam_unix(sudo:session): session closed for user root May 22 02:06:10 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart May 22 02:06:10 volumio volumio[1222]: info: Discovery: Restarting Advertising due to device name change May 22 02:06:10 volumio sudo[2479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service May 22 02:06:10 volumio sudo[2479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:10 volumio systemd[1]: Starting wireless.service - Wireless Services... May 22 02:06:10 volumio systemd[1]: Stopping dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... May 22 02:06:10 volumio dnsmasq[1304]: exiting on receipt of SIGTERM May 22 02:06:10 volumio systemd[1]: dnsmasq.service: Deactivated successfully. May 22 02:06:10 volumio systemd[1]: Stopped dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. May 22 02:06:10 volumio systemd[1]: Stopping hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... May 22 02:06:10 volumio dhcpcd[904]: wlan0: carrier lost May 22 02:06:10 volumio avahi-daemon[874]: Withdrawing address record for 169.254.11.255 on wlan0. May 22 02:06:10 volumio dhcpcd[904]: wlan0: deleting route to 169.254.0.0/16 May 22 02:06:10 volumio dhcpcd[904]: wlan0: deleting default route May 22 02:06:10 volumio systemd[1]: hostapd.service: Deactivated successfully. May 22 02:06:10 volumio systemd[1]: Stopped hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. May 22 02:06:10 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 22 02:06:10 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 22 02:06:10 volumio systemd[1]: welcome.service: Deactivated successfully. May 22 02:06:10 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 22 02:06:10 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 22 02:06:10 volumio sudo[2516]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 May 22 02:06:10 volumio sudo[2516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 22 02:06:10 volumio avahi-daemon[874]: Withdrawing address record for 192.168.211.1 on wlan0. May 22 02:06:10 volumio avahi-daemon[874]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. May 22 02:06:10 volumio sudo[2516]: pam_unix(sudo:session): session closed for user root May 22 02:06:10 volumio avahi-daemon[874]: Interface wlan0.IPv4 no longer relevant for mDNS. May 22 02:06:10 volumio volumio[1222]: info: Discovery: A device disappeared from network May 22 02:06:10 volumio volumio[1222]: info: Discovery: Device volumio disappeared from network May 22 02:06:10 volumio sudo[2525]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down May 22 02:06:10 volumio sudo[2525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 22 02:06:10 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 22 02:06:10 volumio welcome[2521]: Resolved ip:[0] May 22 02:06:10 volumio sudo[2525]: pam_unix(sudo:session): session closed for user root May 22 02:06:10 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 22 02:06:10 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 22 02:06:10 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 22 02:06:10 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 22 02:06:10 volumio systemd[1]: welcome.service: Deactivated successfully. May 22 02:06:10 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 22 02:06:10 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 22 02:06:10 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 22 02:06:10 volumio welcome[2535]: Resolved ip:[0] May 22 02:06:10 volumio sudo[2541]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 22 02:06:10 volumio sudo[2541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:10 volumio sudo[2541]: pam_unix(sudo:session): session closed for user root May 22 02:06:10 volumio sudo[2544]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get May 22 02:06:10 volumio sudo[2544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:10 volumio sudo[2544]: pam_unix(sudo:session): session closed for user root May 22 02:06:10 volumio sudo[2552]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 22 02:06:10 volumio sudo[2552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:10 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 22 02:06:10 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 22 02:06:10 volumio sudo[2552]: pam_unix(sudo:session): session closed for user root May 22 02:06:10 volumio sudo[2556]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan May 22 02:06:10 volumio sudo[2556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:11 volumio volumio[1222]: info: Discovery: A device disappeared from network May 22 02:06:12 volumio ntpd[1111]: IO: Deleting interface #3 wlan0, 192.168.211.1#123, interface stats: received=0, sent=0, dropped=0, active_time=243 secs May 22 02:06:12 volumio ntpd[1111]: IO: Deleting interface #4 wlan0, 169.254.11.255#123, interface stats: received=0, sent=0, dropped=0, active_time=231 secs May 22 02:06:13 volumio sudo[2556]: pam_unix(sudo:session): session closed for user root May 22 02:06:13 volumio sudo[2576]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 22 02:06:13 volumio sudo[2576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:13 volumio sudo[2576]: pam_unix(sudo:session): session closed for user root May 22 02:06:13 volumio sudo[2578]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set CA May 22 02:06:13 volumio sudo[2578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:13 volumio sudo[2578]: pam_unix(sudo:session): session closed for user root May 22 02:06:13 volumio sudo[2586]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 May 22 02:06:13 volumio sudo[2586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 22 02:06:13 volumio sudo[2586]: pam_unix(sudo:session): session closed for user root May 22 02:06:13 volumio sudo[2588]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down May 22 02:06:13 volumio sudo[2588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 22 02:06:13 volumio sudo[2588]: pam_unix(sudo:session): session closed for user root May 22 02:06:13 volumio wpa_supplicant[2593]: Successfully initialized wpa_supplicant May 22 02:06:13 volumio sudo[2594]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd May 22 02:06:13 volumio sudo[2594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 22 02:06:13 volumio dhcpcd[904]: control command: /sbin/dhcpcd May 22 02:06:13 volumio dhcpcd[904]: control_free: No such file or directory May 22 02:06:13 volumio sudo[2594]: pam_unix(sudo:session): session closed for user root May 22 02:06:13 volumio dhcpcd[904]: lo: IAID 00:00:00:00 May 22 02:06:13 volumio dhcpcd[904]: lo: adding address fe80::95f4:68b:f336:d395 May 22 02:06:13 volumio dhcpcd[904]: ipv6_addaddr1: Permission denied May 22 02:06:13 volumio dhcpcd[904]: lo: using static address 127.0.0.1/8 May 22 02:06:13 volumio dhcpcd[904]: lo: adding route to 127.0.0.0/8 May 22 02:06:13 volumio systemd[1]: Reached target ip-changed@lo.target - IP Address changed on lo. May 22 02:06:14 volumio sudo[2626]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:14 volumio sudo[2626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:14 volumio sudo[2626]: pam_unix(sudo:session): session closed for user root May 22 02:06:15 volumio volumio[1222]: info: Discovery: Started advertising with name: Volumio May 22 02:06:15 volumio sudo[2631]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:15 volumio sudo[2631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:15 volumio sudo[2631]: pam_unix(sudo:session): session closed for user root May 22 02:06:16 volumio volumio[1222]: info: Discovery: adding 13c6c992-39a6-4b4d-b9f4-37ba7d6f2709 May 22 02:06:16 volumio volumio[1222]: info: Discovery: Found device Volumio May 22 02:06:16 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:06:16 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:06:16 volumio sudo[2636]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:16 volumio sudo[2636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:16 volumio sudo[2636]: pam_unix(sudo:session): session closed for user root May 22 02:06:17 volumio wpa_supplicant[2623]: wlan0: SME: Trying to authenticate with 0e:ac:8a:66:78:e3 (SSID='BELL189' freq=5785 MHz) May 22 02:06:17 volumio kernel: wlan0: authenticate with 0e:ac:8a:66:78:e3 (local address=bc:30:7d:fe:19:d7) May 22 02:06:17 volumio kernel: wlan0: send auth to 0e:ac:8a:66:78:e3 (try 1/3) May 22 02:06:17 volumio wpa_supplicant[2623]: wlan0: Trying to associate with 0e:ac:8a:66:78:e3 (SSID='BELL189' freq=5785 MHz) May 22 02:06:17 volumio kernel: wlan0: authenticated May 22 02:06:17 volumio kernel: wlan0: associate with 0e:ac:8a:66:78:e3 (try 1/3) May 22 02:06:17 volumio wpa_supplicant[2623]: wlan0: Associated with 0e:ac:8a:66:78:e3 May 22 02:06:17 volumio wpa_supplicant[2623]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 22 02:06:17 volumio wpa_supplicant[2623]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CA May 22 02:06:17 volumio kernel: wlan0: RX AssocResp from 0e:ac:8a:66:78:e3 (capab=0x1011 status=0 aid=23) May 22 02:06:17 volumio kernel: wlan0: associated May 22 02:06:17 volumio kernel: ath: EEPROM regdomain: 0x807c May 22 02:06:17 volumio kernel: ath: EEPROM indicates we should expect a country code May 22 02:06:17 volumio kernel: ath: doing EEPROM country->regdmn map search May 22 02:06:17 volumio kernel: ath: country maps to regdmn code: 0x3a May 22 02:06:17 volumio kernel: ath: Country alpha2 being used: CA May 22 02:06:17 volumio kernel: ath: Regpair used: 0x3a May 22 02:06:17 volumio kernel: ath: regdomain 0x807c dynamically updated by country element May 22 02:06:17 volumio kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by 0e:ac:8a:66:78:e3 May 22 02:06:17 volumio wpa_supplicant[2623]: wlan0: WPA: Key negotiation completed with 0e:ac:8a:66:78:e3 [PTK=CCMP GTK=CCMP] May 22 02:06:17 volumio wpa_supplicant[2623]: wlan0: CTRL-EVENT-CONNECTED - Connection to 0e:ac:8a:66:78:e3 completed [id=0 id_str=] May 22 02:06:17 volumio dhcpcd[904]: wlan0: carrier acquired May 22 02:06:17 volumio dhcpcd[904]: wlan0: connected to Access Point: BELL189 May 22 02:06:17 volumio dhcpcd[904]: wlan0: IAID 7d:fe:19:d7 May 22 02:06:17 volumio sudo[2656]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:17 volumio sudo[2656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:17 volumio sudo[2656]: pam_unix(sudo:session): session closed for user root May 22 02:06:18 volumio dhcpcd[904]: wlan0: soliciting a DHCP lease May 22 02:06:18 volumio dhcpcd[904]: wlan0: soliciting an IPv6 router May 22 02:06:18 volumio sudo[2661]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:18 volumio sudo[2661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:18 volumio sudo[2661]: pam_unix(sudo:session): session closed for user root May 22 02:06:19 volumio dhcpcd[904]: wlan0: offered 192.168.2.21 from 192.168.2.1 May 22 02:06:19 volumio dhcpcd[904]: wlan0: probing address 192.168.2.21/24 May 22 02:06:19 volumio sudo[2666]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:19 volumio sudo[2666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:19 volumio sudo[2666]: pam_unix(sudo:session): session closed for user root May 22 02:06:20 volumio sudo[2670]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:20 volumio sudo[2670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:20 volumio sudo[2670]: pam_unix(sudo:session): session closed for user root May 22 02:06:21 volumio sudo[2674]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:21 volumio sudo[2674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:21 volumio sudo[2674]: pam_unix(sudo:session): session closed for user root May 22 02:06:22 volumio sudo[2692]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:22 volumio sudo[2692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:22 volumio sudo[2692]: pam_unix(sudo:session): session closed for user root May 22 02:06:23 volumio sudo[2696]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:23 volumio sudo[2696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:23 volumio sudo[2696]: pam_unix(sudo:session): session closed for user root May 22 02:06:23 volumio dhcpcd[904]: wlan0: leased 192.168.2.21 for 247877 seconds May 22 02:06:23 volumio avahi-daemon[874]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.21. May 22 02:06:23 volumio avahi-daemon[874]: New relevant interface wlan0.IPv4 for mDNS. May 22 02:06:23 volumio avahi-daemon[874]: Registering new address record for 192.168.2.21 on wlan0.IPv4. May 22 02:06:23 volumio dhcpcd[904]: wlan0: adding route to 192.168.2.0/24 May 22 02:06:23 volumio dhcpcd[904]: wlan0: adding default route via 192.168.2.1 May 22 02:06:23 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 22 02:06:23 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 22 02:06:23 volumio systemd[1]: welcome.service: Deactivated successfully. May 22 02:06:23 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 22 02:06:23 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 22 02:06:24 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 22 02:06:24 volumio welcome[2714]: Resolved ip:[1] 192.168.2.21 May 22 02:06:24 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 22 02:06:24 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 22 02:06:24 volumio volumio[1222]: info: Discovery: this is already registered, 13c6c992-39a6-4b4d-b9f4-37ba7d6f2709 May 22 02:06:24 volumio volumio[1222]: info: Discovery: Found device Volumio May 22 02:06:24 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:06:24 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:06:24 volumio sudo[2727]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 22 02:06:24 volumio sudo[2727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:24 volumio sudo[2727]: pam_unix(sudo:session): session closed for user root May 22 02:06:24 volumio sudo[2730]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 02:06:24 volumio sudo[2730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 22 02:06:24 volumio sudo[2730]: pam_unix(sudo:session): session closed for user root May 22 02:06:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 22 02:06:24 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 22 02:06:24 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 22 02:06:24 volumio systemd[1]: shairport-sync.service: Consumed 2.646s CPU time. May 22 02:06:24 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... May 22 02:06:24 volumio avahi-daemon[874]: Got SIGTERM, quitting. May 22 02:06:24 volumio avahi-daemon[874]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.21. May 22 02:06:24 volumio avahi-daemon[874]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. May 22 02:06:24 volumio avahi-daemon[874]: avahi-daemon 0.8 exiting. May 22 02:06:24 volumio volumio[1222]: info: Discovery: Browse raised the following error Error: dns service error: unknown May 22 02:06:24 volumio volumio[1222]: error: Discovery: Advertisement error: Error: dns service error: unknown May 22 02:06:24 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. May 22 02:06:24 volumio volumio[1222]: error: Discovery: advertisement error: Error: dns service error: unknown May 22 02:06:24 volumio volumio[1222]: info: Discovery: Advertisement raised the following error Error: dns service error: unknown May 22 02:06:24 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. May 22 02:06:24 volumio dbus-daemon[876]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.37' (uid=0 pid=1356 comm="/usr/sbin/smbd --foreground --no-process-group") May 22 02:06:24 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... May 22 02:06:24 volumio avahi-daemon[2735]: Process 874 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) May 22 02:06:24 volumio avahi-daemon[2735]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). May 22 02:06:24 volumio avahi-daemon[2735]: Successfully dropped root privileges. May 22 02:06:24 volumio avahi-daemon[2735]: avahi-daemon 0.8 starting up. May 22 02:06:24 volumio dbus-daemon[876]: [system] Successfully activated service 'org.freedesktop.Avahi' May 22 02:06:24 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. May 22 02:06:24 volumio avahi-daemon[2735]: Successfully called chroot(). May 22 02:06:24 volumio avahi-daemon[2735]: Successfully dropped remaining capabilities. May 22 02:06:24 volumio avahi-daemon[2735]: No service file found in /etc/avahi/services. May 22 02:06:24 volumio avahi-daemon[2735]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.21. May 22 02:06:24 volumio avahi-daemon[2735]: New relevant interface wlan0.IPv4 for mDNS. May 22 02:06:24 volumio avahi-daemon[2735]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. May 22 02:06:24 volumio avahi-daemon[2735]: New relevant interface lo.IPv4 for mDNS. May 22 02:06:24 volumio avahi-daemon[2735]: Network interface enumeration completed. May 22 02:06:24 volumio avahi-daemon[2735]: Registering new address record for 192.168.2.21 on wlan0.IPv4. May 22 02:06:24 volumio avahi-daemon[2735]: Registering new address record for 127.0.0.1 on lo.IPv4. May 22 02:06:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 22 02:06:25 volumio iwconfig[2739]: Error for wireless request "Set Power Management" (8B2C) : May 22 02:06:25 volumio iwconfig[2739]: SET failed on device wlan0 ; Operation not supported. May 22 02:06:25 volumio systemd[1]: Started wireless.service - Wireless Services. May 22 02:06:25 volumio sudo[2479]: pam_unix(sudo:session): session closed for user root May 22 02:06:25 volumio volumio[1222]: verbose: New Socket.io Connection to 192.168.2.21 from 192.168.2.18 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 May 22 02:06:25 volumio ntpd[1111]: IO: Listen normally on 5 wlan0 192.168.2.21:123 May 22 02:06:25 volumio ntpd[1111]: IO: new interface(s) found: waking up resolver May 22 02:06:25 volumio ntpd[1111]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 May 22 02:06:25 volumio ntpd[1111]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 May 22 02:06:25 volumio ntpd[1111]: DNS: Pool taking: 149.56.19.163 May 22 02:06:25 volumio ntpd[1111]: DNS: Pool taking: 51.222.111.13 May 22 02:06:25 volumio ntpd[1111]: DNS: Pool taking: 216.6.2.70 May 22 02:06:25 volumio ntpd[1111]: DNS: Pool taking: 162.159.200.123 May 22 02:06:25 volumio ntpd[1111]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 02:06:25 volumio avahi-daemon[2735]: Server startup complete. Host name is volumio.local. Local service cookie is 1381776053. May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::volumioGetVisibleSources May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:06:25 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:06:25 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 02:06:25 volumio volumio[1222]: info: Received Get System Info May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 02:06:25 volumio volumio[1222]: info: Discovery: Getting this device information May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:06:25 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:06:25 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:06:25 volumio volumio[1222]: info: Listing playlists May 22 02:06:25 volumio volumio[1222]: info: CoreCommandRouter::volumioGetQueue May 22 02:06:25 volumio volumio[1222]: info: CoreStateMachine::getQueue May 22 02:06:25 volumio volumio[1222]: info: CorePlayQueue::getQueue May 22 02:06:26 volumio ntpd[1111]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 May 22 02:06:26 volumio ntpd[1111]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 May 22 02:06:26 volumio ntpd[1111]: DNS: Pool taking: 207.210.46.249 May 22 02:06:26 volumio ntpd[1111]: DNS: Pool taking: 174.142.148.226 May 22 02:06:26 volumio ntpd[1111]: DNS: Pool taking: 23.133.168.244 May 22 02:06:26 volumio ntpd[1111]: DNS: Pool taking: 216.128.178.20 May 22 02:06:26 volumio ntpd[1111]: DNS: Pool taking: 2605:e200:3:4::244 May 22 02:06:26 volumio ntpd[1111]: DNS: Pool taking: 2606:4700:f1::123 May 22 02:06:26 volumio ntpd[1111]: DNS: Pool taking: 2602:fbc7:2:0:beef:d00d:f00b:5551 May 22 02:06:26 volumio ntpd[1111]: DNS: Pool taking: 2607:5300:205:200::5144 May 22 02:06:26 volumio ntpd[1111]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 May 22 02:06:27 volumio ntpd[1111]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 May 22 02:06:27 volumio ntpd[1111]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 May 22 02:06:27 volumio ntpd[1111]: DNS: Pool taking: 96.53.17.246 May 22 02:06:27 volumio ntpd[1111]: DNS: Pool taking: 216.232.132.102 May 22 02:06:27 volumio ntpd[1111]: DNS: Pool taking: 70.55.19.46 May 22 02:06:27 volumio ntpd[1111]: DNS: Pool taking: 54.39.196.172 May 22 02:06:27 volumio ntpd[1111]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 May 22 02:06:28 volumio ntpd[1111]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 May 22 02:06:28 volumio ntpd[1111]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 May 22 02:06:28 volumio ntpd[1111]: DNS: Pool skipping: 216.128.178.20 May 22 02:06:28 volumio ntpd[1111]: DNS: Pool skipping: 207.210.46.249 May 22 02:06:28 volumio ntpd[1111]: DNS: Pool taking: 173.183.146.26 May 22 02:06:28 volumio ntpd[1111]: DNS: Pool taking: 217.180.209.214 May 22 02:06:28 volumio ntpd[1111]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 22 02:06:29 volumio volumio[1222]: info: Adding plugin bluetooth to MyMusic Plugins May 22 02:06:29 volumio volumio[1222]: info: Adding plugin multiroom to MyMusic Plugins May 22 02:06:29 volumio volumio[1222]: info: Adding plugin metavolumio to MyMusic Plugins May 22 02:06:29 volumio volumio[1222]: info: Adding plugin cd_controller to MyMusic Plugins May 22 02:06:29 volumio volumio[1222]: info: Adding plugin smart_inputs to MyMusic Plugins May 22 02:06:29 volumio volumio[1222]: info: Adding plugin tidalconnect to MyMusic Plugins May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 22 02:06:29 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 02:06:29 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 02:06:29 volumio volumio[1222]: info: Starting MyVolumio Remote Streaming Endpoints May 22 02:06:29 volumio volumio[1222]: info: MyVolumio not started May 22 02:06:29 volumio volumio[1222]: info: Initializing device activation check May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 22 02:06:29 volumio volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 22 02:06:30 volumio volumio[1222]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 22 02:06:30 volumio volumio[1222]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 22 02:06:30 volumio volumio[1222]: info: Streaming services startup May 22 02:06:30 volumio volumio[1222]: info: Starting Streaming Daemon May 22 02:06:30 volumio sudo[2771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 22 02:06:30 volumio sudo[2771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:30 volumio volumio[1222]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 22 02:06:30 volumio sudo[2771]: pam_unix(sudo:session): session closed for user root May 22 02:06:30 volumio volumio[1222]: info: Discovery: Started advertising with name: Volumio May 22 02:06:30 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection May 22 02:06:30 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo May 22 02:06:30 volumio volumio[1222]: error: Cannot start Volumio Streaming Daemon May 22 02:06:30 volumio volumio[1222]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 22 02:06:30 volumio volumio[1222]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 22 02:06:30 volumio sudo[2779]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 02:06:30 volumio sudo[2779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:30 volumio sudo[2779]: pam_unix(sudo:session): session closed for user root May 22 02:06:30 volumio sudo[2783]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 May 22 02:06:30 volumio sudo[2783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:30 volumio sudo[2783]: pam_unix(sudo:session): session closed for user root May 22 02:06:31 volumio ntpd[1111]: CLOCK: time stepped by -0.468295 May 22 02:06:31 volumio ntpd[1111]: INIT: MRU 10922 entries, 13 hash bits, 65536 bytes May 22 02:06:32 volumio volumio[1222]: info: Volumio Network Manager: Network status updated: 2 May 22 02:06:34 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart May 22 02:06:34 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart May 22 02:06:34 volumio volumio[1222]: info: Refreshing Cached IP Addresses May 22 02:06:34 volumio sudo[2802]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli May 22 02:06:34 volumio sudo[2802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:34 volumio sudo[2804]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 22 02:06:34 volumio sudo[2804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:34 volumio sudo[2804]: pam_unix(sudo:session): session closed for user root May 22 02:06:34 volumio sudo[2806]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 02:06:34 volumio sudo[2806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:34 volumio sudo[2806]: pam_unix(sudo:session): session closed for user root May 22 02:06:34 volumio sudo[2802]: pam_unix(sudo:session): session closed for user root May 22 02:06:36 volumio volumio[1222]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 02:06:36 volumio volumio[1222]: info: Retrieving Cloud Streaming UI May 22 02:06:36 volumio volumio[1222]: info: Getting Tidal Cloud Configuration May 22 02:06:36 volumio volumio[1222]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 02:06:36 volumio volumio[1222]: info: Getting Qobuz Cloud Configuration May 22 02:06:36 volumio volumio[1222]: info: Asking plugin for UI Config May 22 02:06:36 volumio volumio[1222]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 02:06:36 volumio volumio[1222]: info: Getting Spotify Cloud Configuration May 22 02:06:36 volumio volumio[1222]: info: Asking plugin for UI Config May 22 02:06:36 volumio volumio[1222]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 02:06:36 volumio volumio[1222]: info: Saving Spotify Acccount May 22 02:06:36 volumio volumio[1222]: info: Got Tidal Cloud Configuration May 22 02:06:36 volumio volumio[1222]: info: Got it May 22 02:06:36 volumio volumio[1222]: info: Got it May 22 02:06:36 volumio volumio[1222]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 22 02:06:36 volumio volumio[1222]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 02:06:36 volumio volumio[1222]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') May 22 02:06:36 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. May 22 02:06:44 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 02:06:44 volumio volumio[1222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 22 02:06:44 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:06:44 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:06:44 volumio sudo[2829]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 22 02:06:44 volumio sudo[2829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:44 volumio sudo[2831]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 02:06:44 volumio sudo[2831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:44 volumio sudo[2829]: pam_unix(sudo:session): session closed for user root May 22 02:06:44 volumio sudo[2831]: pam_unix(sudo:session): session closed for user root May 22 02:06:44 volumio sudo[2834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 22 02:06:44 volumio sudo[2834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:06:44 volumio sudo[2834]: pam_unix(sudo:session): session closed for user root May 22 02:06:44 volumio volumio[1222]: info: Upmpdcli Daemon Started May 22 02:06:45 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: wizard , getDonation May 22 02:06:45 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware May 22 02:06:45 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: wizard , getDonationsArray May 22 02:06:45 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: wizard , getDoneMessage May 22 02:06:45 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware May 22 02:06:49 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 02:06:49 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 02:06:49 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 22 02:06:49 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 22 02:06:49 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 22 02:06:49 volumio volumio[1222]: info: CoreCommandRouter::volumioGetBrowseSources May 22 02:06:49 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 22 02:06:57 volumio volumio[1222]: info: CALLMETHOD: system_controller system saveUpdateSettings [object Object] May 22 02:06:57 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , saveUpdateSettings May 22 02:06:57 volumio volumio[1222]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'value') May 22 02:07:02 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction May 22 02:07:02 volumio volumio[1222]: info: CoreCommandRouter::Reload Ui May 22 02:07:02 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , setShowWizard May 22 02:07:02 volumio volumio[1222]: info: Wizard terminated Successfully May 22 02:07:02 volumio volumio[1222]: info: CoreCommandRouter::volumiosetStartupVolume May 22 02:07:02 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 02:07:02 volumio sudo[2886]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 22 02:07:02 volumio sudo[2886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:07:02 volumio sudo[2886]: pam_unix(sudo:session): session closed for user root May 22 02:07:02 volumio sudo[2888]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 02:07:02 volumio sudo[2888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:07:02 volumio sudo[2888]: pam_unix(sudo:session): session closed for user root May 22 02:07:02 volumio volumio[1222]: verbose: New Socket.io Connection to 192.168.2.21 from 192.168.2.18 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 02:07:03 volumio volumio[1222]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::volumioGetVisibleSources May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:03 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 02:07:03 volumio volumio[1222]: info: Received Get System Info May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 02:07:03 volumio volumio[1222]: info: Discovery: Getting this device information May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:03 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:03 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:03 volumio volumio[1222]: info: Listing playlists May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 22 02:07:03 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 02:07:04 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:04 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:04 volumio volumio[1222]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::volumioGetVisibleSources May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:05 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 02:07:05 volumio volumio[1222]: info: Received Get System Info May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 02:07:05 volumio volumio[1222]: info: Discovery: Getting this device information May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:05 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:05 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:05 volumio volumio[1222]: info: Listing playlists May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 02:07:05 volumio volumio[1222]: info: Received Get System Info May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 02:07:05 volumio volumio[1222]: info: Discovery: Getting this device information May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:05 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken May 22 02:07:05 volumio volumio[1222]: info: MyVolumio login type: Token May 22 02:07:05 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:05 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:05 volumio volumio[1222]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 02:07:06 volumio volumio[1222]: info: Received Get System Info May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 02:07:06 volumio volumio[1222]: info: Discovery: Getting this device information May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:06 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 02:07:06 volumio volumio[1222]: info: Received Get System Info May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 02:07:06 volumio volumio[1222]: info: Discovery: Getting this device information May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:06 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 02:07:06 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 22 02:07:08 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 02:07:08 volumio volumio[1222]: info: Received Get System Info May 22 02:07:08 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 02:07:08 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 02:07:08 volumio volumio[1222]: info: Discovery: Getting this device information May 22 02:07:08 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:08 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:08 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 02:07:08 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 02:07:08 volumio volumio[1222]: info: Received Get System Info May 22 02:07:08 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 02:07:08 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 02:07:08 volumio volumio[1222]: info: Discovery: Getting this device information May 22 02:07:08 volumio volumio[1222]: info: CoreCommandRouter::volumioGetState May 22 02:07:08 volumio volumio[1222]: info: CorePlayQueue::getTrack 0 May 22 02:07:08 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 02:07:13 volumio volumio[1222]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 22 02:07:14 volumio volumio[1222]: info: MyVolumio token set successfully May 22 02:07:14 volumio volumio[1222]: info: MYVOLUMIO: Adding device May 22 02:07:14 volumio volumio[1222]: info: MYVOLUMIO: Evaluating Server May 22 02:07:14 volumio volumio[1222]: info: MyVolumio status changed May 22 02:07:14 volumio volumio[1222]: info: Streaming services startup May 22 02:07:14 volumio volumio[1222]: info: Starting Streaming Daemon May 22 02:07:14 volumio volumio[1222]: info: Removing browser output: myVolumio user plan is not superstar May 22 02:07:14 volumio volumio[1222]: info: Removing audio output: May 22 02:07:14 volumio volumio[1222]: info: Stoppping Tunnel 1 May 22 02:07:14 volumio sudo[2932]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 22 02:07:14 volumio sudo[2932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:07:14 volumio sudo[2934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 22 02:07:14 volumio sudo[2934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 22 02:07:14 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 22 02:07:14 volumio sudo[2932]: pam_unix(sudo:session): session closed for user root May 22 02:07:14 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 22 02:07:14 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 22 02:07:14 volumio volumio[1222]: error: Cannot start Volumio Streaming Daemon May 22 02:07:14 volumio volumio[1222]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 22 02:07:14 volumio volumio[1222]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 22 02:07:14 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 22 02:07:14 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 22 02:07:14 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 22 02:07:14 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 22 02:07:14 volumio dbus-daemon[876]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.42' (uid=0 pid=2938 comm="timedatectl show --property=NTPSynchronized --valu") May 22 02:07:14 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 22 02:07:14 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 22 02:07:14 volumio sudo[2934]: pam_unix(sudo:session): session closed for user root May 22 02:07:14 volumio volumio[1222]: info: Remote SSH Stopped May 22 02:07:14 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 22 02:07:14 volumio dbus-daemon[876]: [system] Successfully activated service 'org.freedesktop.timedate1' May 22 02:07:14 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 22 02:07:14 volumio setdatetime-helper.sh[2937]: Time is not synchronized. Attempting to sync... May 22 02:07:14 volumio sudo[2946]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 22 May 2025 06:07:14 GMT#015' May 22 02:07:14 volumio sudo[2946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 22 02:07:14 volumio setdatetime-helper.sh[2947]: Thu May 22 02:07:14 EDT 2025 May 22 02:07:14 volumio setdatetime-helper.sh[2937]: Time synchronized successfully. May 22 02:07:14 volumio sudo[2946]: pam_unix(sudo:session): session closed for user root May 22 02:07:14 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 22 02:07:14 volumio systemd-journald[498]: Time jumped backwards, rotating. May 22 02:07:14 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 22 02:07:14 volumio volumio[1222]: error: Failed to ping endpoint au1.myvolumio.org : unknown error May 22 02:07:14 volumio volumio[1222]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 22 02:07:14 volumio volumio[1222]: Error: Unable to resolve or reject the same promise twice May 22 02:07:14 volumio volumio[1222]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 22 02:07:14 volumio volumio[1222]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32371) May 22 02:07:14 volumio volumio[1222]: at Socket.emit (node:events:514:28) May 22 02:07:14 volumio volumio[1222]: at addChunk (node:internal/streams/readable:343:12) May 22 02:07:14 volumio volumio[1222]: at readableAddChunk (node:internal/streams/readable:316:9) May 22 02:07:14 volumio volumio[1222]: at Readable.push (node:internal/streams/readable:253:10) May 22 02:07:14 volumio volumio[1222]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) May 22 02:07:14 volumio volumio[1222]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 22 02:07:14 volumio sudo[2963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-22 02:06' May 22 02:07:14 volumio sudo[2963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="a9e1adf9740e24b1b1a392b34b6acf37064d0420" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed May 21 14:28:31 UTC 2025" VOLUMIO_VERSION="0.068" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="244a93a40b2e4c18f4124fa55cfb0ef0"