Dec 15 16:54:05 volumio volumio[1137]: info: CALLMETHOD: system_controller network saveHotspotSettings [object Object] Dec 15 16:54:05 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: network , saveHotspotSettings Dec 15 16:54:06 volumio sudo[6392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hostapd/hostapd.conf Dec 15 16:54:06 volumio sudo[6392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:06 volumio sudo[6392]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:06 volumio volumio[1137]: info: Permissions for /etc/hostapd/hostapd.conf Dec 15 16:54:06 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Dec 15 16:54:06 volumio volumio[1137]: info: Discovery: Restarting Advertising due to device name change Dec 15 16:54:06 volumio sudo[6395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Dec 15 16:54:06 volumio sudo[6395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:06 volumio systemd[1]: Stopping wireless.service - Wireless Services... Dec 15 16:54:06 volumio systemd[1]: wireless.service: Killing process 2564 (wpa_supplicant) with signal SIGKILL. Dec 15 16:54:06 volumio systemd[1]: wireless.service: Deactivated successfully. Dec 15 16:54:06 volumio systemd[1]: Stopped wireless.service - Wireless Services. Dec 15 16:54:06 volumio systemd[1]: wireless.service: Consumed 2min 3.468s CPU time. Dec 15 16:54:06 volumio systemd[1]: Starting wireless.service - Wireless Services... Dec 15 16:54:07 volumio wireless.js[6404]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Dec 15 16:54:07 volumio wireless.js[6404]: WIRELESS.JS: Wireless.js initializing wireless flow Dec 15 16:54:07 volumio wireless.js[6404]: WIRELESS.JS: Cleaning previous... Dec 15 16:54:07 volumio sudo[6425]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 15 16:54:07 volumio sudo[6425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 16:54:07 volumio avahi-daemon[2680]: Withdrawing address record for 192.168.2.77 on wlan0. Dec 15 16:54:07 volumio avahi-daemon[2680]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.77. Dec 15 16:54:07 volumio dhcpcd[830]: wlan0: pid 6426 deleted IP address 192.168.2.77/24 Dec 15 16:54:07 volumio dhcpcd[830]: wlan0: deleting route to 192.168.2.0/24 Dec 15 16:54:07 volumio avahi-daemon[2680]: Interface wlan0.IPv4 no longer relevant for mDNS. Dec 15 16:54:07 volumio dhcpcd[830]: wlan0: deleting default route via 192.168.2.1 Dec 15 16:54:07 volumio sudo[6425]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:07 volumio sudo[6429]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 15 16:54:07 volumio sudo[6429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 16:54:07 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 15 16:54:07 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 15 16:54:07 volumio systemd[1]: welcome.service: Deactivated successfully. Dec 15 16:54:07 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 15 16:54:07 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 15 16:54:07 volumio dhcpcd[830]: wlan0: soliciting a DHCP lease Dec 15 16:54:07 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 15 16:54:08 volumio dhcpcd[830]: wlan0: carrier lost Dec 15 16:54:08 volumio sudo[6429]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:08 volumio welcome[6440]: Resolved ip:[0] Dec 15 16:54:08 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 15 16:54:08 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 15 16:54:08 volumio wireless.js[6404]: WIRELESS.JS: Stopped aP Dec 15 16:54:08 volumio sudo[6466]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 15 16:54:08 volumio sudo[6466]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:08 volumio sudo[6466]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:08 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 15 16:54:08 volumio sudo[6468]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Dec 15 16:54:08 volumio sudo[6468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:08 volumio sudo[6468]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:08 volumio sudo[6476]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 15 16:54:08 volumio sudo[6476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:08 volumio sudo[6476]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:08 volumio sudo[6479]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Dec 15 16:54:08 volumio sudo[6479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:09 volumio sudo[6479]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:09 volumio wireless.js[6404]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: CN Dec 15 16:54:09 volumio sudo[6486]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 15 16:54:09 volumio sudo[6486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:09 volumio sudo[6486]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:09 volumio sudo[6488]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set CN Dec 15 16:54:09 volumio sudo[6488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:09 volumio sudo[6488]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:09 volumio wireless.js[6404]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: CN Dec 15 16:54:09 volumio wireless.js[6404]: WIRELESS.JS: Start wireless flow Dec 15 16:54:09 volumio wireless.js[6404]: WIRELESS.JS: Stopped hotspot (if there).. Dec 15 16:54:09 volumio sudo[6498]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 15 16:54:09 volumio sudo[6498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 16:54:09 volumio sudo[6498]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:09 volumio sudo[6500]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 15 16:54:09 volumio sudo[6500]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 16:54:09 volumio sudo[6500]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:09 volumio wireless.js[6404]: WIRELESS.JS: DHCP IP fallback Dec 15 16:54:09 volumio wireless.js[6404]: WIRELESS.JS: Start ap Dec 15 16:54:09 volumio wpa_supplicant[6507]: Successfully initialized wpa_supplicant Dec 15 16:54:09 volumio sudo[6508]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Dec 15 16:54:09 volumio sudo[6508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 16:54:09 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 15 16:54:09 volumio dhcpcd[830]: ps_ctl_dispatch: cannot handle another client Dec 15 16:54:09 volumio dhcpcd[830]: control_free: No such file or directory Dec 15 16:54:09 volumio sudo[6508]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:10 volumio wpa_supplicant[6512]: wlan0: Trying to associate with e2:3b:7e:9e:06:3b (SSID='ChinaNet-KMSHK4' freq=2412 MHz) Dec 15 16:54:10 volumio wpa_supplicant[6512]: wlan0: Associated with e2:3b:7e:9e:06:3b Dec 15 16:54:10 volumio wpa_supplicant[6512]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 15 16:54:10 volumio wpa_supplicant[6512]: wlan0: WPA: Key negotiation completed with e2:3b:7e:9e:06:3b [PTK=CCMP GTK=CCMP] Dec 15 16:54:10 volumio wpa_supplicant[6512]: wlan0: CTRL-EVENT-CONNECTED - Connection to e2:3b:7e:9e:06:3b completed [id=0 id_str=] Dec 15 16:54:10 volumio dhcpcd[830]: wlan0: carrier acquired Dec 15 16:54:10 volumio dhcpcd[830]: wlan0: IAID eb:12:8d:f1 Dec 15 16:54:10 volumio wireless.js[6404]: WIRELESS.JS: trying... Dec 15 16:54:10 volumio sudo[6518]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 15 16:54:10 volumio sudo[6518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:10 volumio sudo[6518]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:11 volumio dhcpcd[830]: wlan0: soliciting an IPv6 router Dec 15 16:54:11 volumio volumio[1137]: info: Discovery: Started advertising with name: Volumio Dec 15 16:54:11 volumio dhcpcd[830]: wlan0: soliciting a DHCP lease Dec 15 16:54:11 volumio dhcpcd[830]: wlan0: offered 192.168.2.77 from 192.168.2.1 Dec 15 16:54:11 volumio dhcpcd[830]: wlan0: probing address 192.168.2.77/24 Dec 15 16:54:11 volumio wireless.js[6404]: WIRELESS.JS: trying... Dec 15 16:54:11 volumio sudo[6527]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 15 16:54:11 volumio sudo[6527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:11 volumio sudo[6527]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:12 volumio ntpd[908]: IO: Deleting interface #5 wlan0, 192.168.2.77#123, interface stats: received=103, sent=409, dropped=0, active_time=1639 secs Dec 15 16:54:12 volumio ntpd[908]: PROTO: 101.43.66.2 unlink local addr 192.168.2.77 -> Dec 15 16:54:12 volumio ntpd[908]: PROTO: 117.80.231.60 unlink local addr 192.168.2.77 -> Dec 15 16:54:12 volumio ntpd[908]: PROTO: 162.159.200.123 unlink local addr 192.168.2.77 -> Dec 15 16:54:12 volumio ntpd[908]: PROTO: 116.203.151.74 unlink local addr 192.168.2.77 -> Dec 15 16:54:12 volumio ntpd[908]: PROTO: 111.230.189.174 unlink local addr 192.168.2.77 -> Dec 15 16:54:12 volumio ntpd[908]: PROTO: 139.199.215.251 unlink local addr 192.168.2.77 -> Dec 15 16:54:12 volumio ntpd[908]: PROTO: 210.28.130.4 unlink local addr 192.168.2.77 -> Dec 15 16:54:12 volumio ntpd[908]: PROTO: 193.182.111.143 unlink local addr 192.168.2.77 -> Dec 15 16:54:12 volumio ntpd[908]: PROTO: 119.28.206.193 unlink local addr 192.168.2.77 -> Dec 15 16:54:12 volumio volumio[1137]: info: Volumio Network Manager: Network status updated: 0 Dec 15 16:54:12 volumio wireless.js[6404]: WIRELESS.JS: trying... Dec 15 16:54:12 volumio sudo[6550]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 15 16:54:12 volumio sudo[6550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:12 volumio sudo[6550]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:13 volumio wireless.js[6404]: WIRELESS.JS: trying... Dec 15 16:54:13 volumio sudo[6556]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 15 16:54:13 volumio sudo[6556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:13 volumio sudo[6556]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:14 volumio wireless.js[6404]: WIRELESS.JS: trying... Dec 15 16:54:14 volumio sudo[6562]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 15 16:54:14 volumio sudo[6562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:14 volumio sudo[6562]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:15 volumio wireless.js[6404]: WIRELESS.JS: trying... Dec 15 16:54:15 volumio sudo[6568]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 15 16:54:15 volumio sudo[6568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:15 volumio sudo[6568]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:16 volumio wireless.js[6404]: WIRELESS.JS: trying... Dec 15 16:54:16 volumio dhcpcd[830]: wlan0: leased 192.168.2.77 for 86400 seconds Dec 15 16:54:16 volumio avahi-daemon[2680]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.77. Dec 15 16:54:16 volumio dhcpcd[830]: wlan0: adding route to 192.168.2.0/24 Dec 15 16:54:16 volumio avahi-daemon[2680]: New relevant interface wlan0.IPv4 for mDNS. Dec 15 16:54:16 volumio avahi-daemon[2680]: Registering new address record for 192.168.2.77 on wlan0.IPv4. Dec 15 16:54:16 volumio dhcpcd[830]: wlan0: adding default route via 192.168.2.1 Dec 15 16:54:16 volumio sudo[6575]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 15 16:54:16 volumio sudo[6575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:16 volumio sudo[6575]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:16 volumio wireless.js[6404]: WIRELESS.JS: Connected to: ----ChinaNet-KMSHK4---- Dec 15 16:54:16 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 15 16:54:16 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 15 16:54:16 volumio systemd[1]: welcome.service: Deactivated successfully. Dec 15 16:54:16 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 15 16:54:16 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 15 16:54:17 volumio sudo[6590]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 16:54:17 volumio sudo[6590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 16:54:17 volumio sudo[6590]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:17 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 15 16:54:17 volumio wireless.js[6404]: WIRELESS.JS: ... joined AP, wlan0 IPv4 is 192.168.2.77, ipV6 is undefined Dec 15 16:54:17 volumio wireless.js[6404]: WIRELESS.JS: It's done! AP Dec 15 16:54:17 volumio welcome[6587]: Resolved ip:[1] 192.168.2.77 Dec 15 16:54:17 volumio wireless.js[6404]: WIRELESS.JS: Restarting avahi-daemon... Dec 15 16:54:17 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 15 16:54:17 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 15 16:54:17 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 16:54:17 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 16:54:17 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 16:54:17 volumio systemd[1]: shairport-sync.service: Consumed 7.484s CPU time. Dec 15 16:54:17 volumio avahi-daemon[2680]: Got SIGTERM, quitting. Dec 15 16:54:17 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 15 16:54:17 volumio wireless.js[6404]: WIRELESS.JS: Notified systemd about wireless ready Dec 15 16:54:17 volumio avahi-daemon[2680]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.77. Dec 15 16:54:17 volumio avahi-daemon[2680]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 15 16:54:17 volumio avahi-daemon[2680]: avahi-daemon 0.8 exiting. Dec 15 16:54:17 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Dec 15 16:54:17 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 15 16:54:17 volumio volumio[1137]: error: Discovery: Advertisement error: Error: dns service error: unknown Dec 15 16:54:17 volumio volumio[1137]: info: Discovery: mDNS temporarily unavailable during network transition Dec 15 16:54:17 volumio systemd[1]: Started wireless.service - Wireless Services. Dec 15 16:54:17 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 15 16:54:17 volumio sudo[6395]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:17 volumio dbus-daemon[728]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.33' (uid=0 pid=1186 comm="/usr/sbin/smbd --foreground --no-process-group") Dec 15 16:54:17 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 15 16:54:17 volumio avahi-daemon[6611]: Process 2680 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Dec 15 16:54:17 volumio avahi-daemon[6611]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Dec 15 16:54:17 volumio avahi-daemon[6611]: Successfully dropped root privileges. Dec 15 16:54:17 volumio avahi-daemon[6611]: avahi-daemon 0.8 starting up. Dec 15 16:54:17 volumio dbus-daemon[728]: [system] Successfully activated service 'org.freedesktop.Avahi' Dec 15 16:54:17 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 15 16:54:17 volumio avahi-daemon[6611]: Successfully called chroot(). Dec 15 16:54:17 volumio avahi-daemon[6611]: Successfully dropped remaining capabilities. Dec 15 16:54:17 volumio avahi-daemon[6611]: No service file found in /etc/avahi/services. Dec 15 16:54:17 volumio avahi-daemon[6611]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.77. Dec 15 16:54:17 volumio avahi-daemon[6611]: New relevant interface wlan0.IPv4 for mDNS. Dec 15 16:54:17 volumio avahi-daemon[6611]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 15 16:54:17 volumio avahi-daemon[6611]: New relevant interface lo.IPv4 for mDNS. Dec 15 16:54:17 volumio avahi-daemon[6611]: Network interface enumeration completed. Dec 15 16:54:17 volumio avahi-daemon[6611]: Registering new address record for 192.168.2.77 on wlan0.IPv4. Dec 15 16:54:17 volumio avahi-daemon[6611]: Registering new address record for 127.0.0.1 on lo.IPv4. Dec 15 16:54:17 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 16:54:18 volumio ntpd[908]: IO: Listen normally on 6 wlan0 192.168.2.77:123 Dec 15 16:54:18 volumio ntpd[908]: IO: new interface(s) found: waking up resolver Dec 15 16:54:18 volumio avahi-daemon[6611]: Server startup complete. Host name is volumio.local. Local service cookie is 3113143132. Dec 15 16:54:22 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Dec 15 16:54:22 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Dec 15 16:54:22 volumio sudo[6640]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 16:54:22 volumio sudo[6640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:22 volumio sudo[6640]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:22 volumio sudo[6644]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 15 16:54:22 volumio sudo[6644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:22 volumio sudo[6644]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:22 volumio volumio[1137]: info: Volumio Network Manager: Network status updated: 2 Dec 15 16:54:27 volumio volumio[1137]: info: Discovery: Started advertising with name: Volumio Dec 15 16:54:27 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Dec 15 16:54:27 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Dec 15 16:54:27 volumio volumio[1137]: info: Refreshing Cached IP Addresses Dec 15 16:54:27 volumio sudo[6676]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Dec 15 16:54:27 volumio sudo[6676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:27 volumio sudo[6676]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:27 volumio sudo[6678]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 16:54:27 volumio sudo[6678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:27 volumio sudo[6680]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 16:54:27 volumio sudo[6680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:27 volumio sudo[6678]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:27 volumio sudo[6680]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:27 volumio sudo[6688]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 16:54:27 volumio sudo[6688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:27 volumio sudo[6688]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:27 volumio sudo[6690]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 16:54:27 volumio sudo[6690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:27 volumio sudo[6690]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:28 volumio volumio[1137]: verbose: New Socket.io Connection to 192.168.2.77 from 192.168.2.5 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Edg/143.0.0.0 Engine version: 3 Transport: polling Total Clients: 4 Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::volumioGetState Dec 15 16:54:28 volumio volumio[1137]: info: CorePlayQueue::getTrack 70 Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 16:54:28 volumio volumio[1137]: info: Received Get System Info Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 16:54:28 volumio volumio[1137]: info: Discovery: Getting this device information Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::volumioGetState Dec 15 16:54:28 volumio volumio[1137]: info: CorePlayQueue::getTrack 70 Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::volumioGetState Dec 15 16:54:28 volumio volumio[1137]: info: CorePlayQueue::getTrack 70 Dec 15 16:54:28 volumio volumio[1137]: info: Listing playlists Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 15 16:54:28 volumio volumio[1137]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E6%B8%A9%E5%A5%95%E5%BF%83/%E4%B8%80%E8%B7%AF%E7%94%9F%E8%8A%B1/f978535a-e338-43ee-a51a-a0dcb7015814.jpg' Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Dec 15 16:54:28 volumio sudo[6698]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Dec 15 16:54:28 volumio sudo[6698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:28 volumio sudo[6703]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 15 16:54:28 volumio sudo[6703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:28 volumio sudo[6698]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:28 volumio sudo[6703]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:28 volumio sudo[6709]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 15 16:54:28 volumio sudo[6709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:28 volumio sudo[6715]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Dec 15 16:54:28 volumio sudo[6715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:28 volumio sudo[6721]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 16:54:28 volumio sudo[6721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:28 volumio sudo[6709]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:28 volumio sudo[6721]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:28 volumio sudo[6715]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:28 volumio sudo[6729]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 15 16:54:28 volumio sudo[6724]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 16:54:28 volumio sudo[6729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:28 volumio sudo[6724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:28 volumio sudo[6724]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:28 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 15 16:54:29 volumio sudo[6729]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:29 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 15 16:54:29 volumio volumio[1137]: info: Received Get System Info Dec 15 16:54:29 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 16:54:29 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 16:54:29 volumio volumio[1137]: info: Discovery: Getting this device information Dec 15 16:54:29 volumio volumio[1137]: info: CoreCommandRouter::volumioGetState Dec 15 16:54:29 volumio volumio[1137]: info: CorePlayQueue::getTrack 70 Dec 15 16:54:29 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 16:54:29 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 15 16:54:37 volumio sudo[6768]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 16:54:37 volumio sudo[6768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:37 volumio sudo[6768]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:37 volumio sudo[6770]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 16:54:37 volumio sudo[6770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:37 volumio sudo[6770]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:37 volumio sudo[6773]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 16:54:37 volumio sudo[6773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 16:54:37 volumio sudo[6773]: pam_unix(sudo:session): session closed for user root Dec 15 16:54:37 volumio volumio[1137]: info: Upmpdcli Daemon Started Dec 15 16:54:38 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 15 16:54:46 volumio volumio[1137]: info: CoreCommandRouter::volumioGetState Dec 15 16:54:46 volumio volumio[1137]: info: CorePlayQueue::getTrack 70 Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::volumioNext Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::next Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::stop Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::stPlaybackTimer Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::updateTrackBlock Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrackBlock Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 70 Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::serviceStop Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 70 Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::serviceStop Dec 15 16:54:50 volumio volumio[1137]: info: ControllerMpd::stop Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand stop Dec 15 16:54:50 volumio volumio[1137]: info: Dec 15 16:54:50 volumio volumio[1137]: ---------------------------- MPD announces state update: player Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand stop took 19 milliseconds Dec 15 16:54:50 volumio volumio[1137]: info: ControllerMpd::getState Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand status Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::play index undefined Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::startPlaybackTimer Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::clearAddPlayTracks USB/86D5-4CBE/音乐/下一个天亮 - 郭静.flac Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand stop Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::updateTrackBlock Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrackBlock Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand status took 2 milliseconds Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand stop took 2 milliseconds Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::parseState Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand clear Dec 15 16:54:50 volumio volumio[1137]: info: Dec 15 16:54:50 volumio volumio[1137]: ---------------------------- MPD announces system playlist update Dec 15 16:54:50 volumio volumio[1137]: info: Ignoring MPD Status Update Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand clear took 2 milliseconds Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::parseTrackInfo Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand add "USB/86D5-4CBE/音乐/下一个天亮 - 郭静.flac" Dec 15 16:54:50 volumio volumio[1137]: info: ControllerMpd::pushState Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::servicePushState Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:50 volumio volumio[1137]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"一路生花","artist":"温奕心","album":"一路生花","uri":"USB/86D5-4CBE/音乐/一路生花 - 温奕心.flac","trackType":"flac"} Dec 15 16:54:50 volumio volumio[1137]: verbose: CURRENT POSITION 71 Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::syncState stateService stop Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::syncState currentStatus stop Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:50 volumio volumio[1137]: info: No code Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:50 volumio volumio[1137]: info: ------------------------------ 38ms Dec 15 16:54:50 volumio volumio[1137]: error: updateQueue error: null Dec 15 16:54:50 volumio volumio[1137]: info: Dec 15 16:54:50 volumio volumio[1137]: ---------------------------- MPD announces system playlist update Dec 15 16:54:50 volumio volumio[1137]: info: Ignoring MPD Status Update Dec 15 16:54:50 volumio volumio[1137]: info: ------------------------------ 34ms Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand add "USB/86D5-4CBE/音乐/下一个天亮 - 郭静.flac" took 34 milliseconds Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand play Dec 15 16:54:50 volumio volumio[1137]: info: ------------------------------ 14ms Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand play took 13 milliseconds Dec 15 16:54:50 volumio volumio[1137]: info: Dec 15 16:54:50 volumio volumio[1137]: ---------------------------- MPD announces state update: player Dec 15 16:54:50 volumio volumio[1137]: info: ControllerMpd::getState Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand status Dec 15 16:54:50 volumio volumio[1137]: info: Dec 15 16:54:50 volumio volumio[1137]: ---------------------------- MPD announces state update: player Dec 15 16:54:50 volumio volumio[1137]: info: ControllerMpd::getState Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand status Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand status took 4 milliseconds Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::parseState Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand status took 5 milliseconds Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::parseState Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::parseTrackInfo Dec 15 16:54:50 volumio volumio[1137]: info: ControllerMpd::pushState Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::servicePushState Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:50 volumio volumio[1137]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":267,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"下一个天亮","artist":"郭静","album":"下一个天亮","uri":"USB/86D5-4CBE/音乐/下一个天亮 - 郭静.flac","trackType":"flac"} Dec 15 16:54:50 volumio volumio[1137]: verbose: CURRENT POSITION 71 Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::syncState stateService play Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::syncState currentStatus stop Dec 15 16:54:50 volumio volumio[1137]: info: ------------------------------ 14ms Dec 15 16:54:50 volumio volumio[1137]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 15 16:54:50 volumio volumio[1137]: verbose: ControllerMpd::parseTrackInfo Dec 15 16:54:50 volumio volumio[1137]: info: ControllerMpd::pushState Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::servicePushState Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:50 volumio volumio[1137]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":267,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"下一个天亮","artist":"郭静","album":"下一个天亮","uri":"USB/86D5-4CBE/音乐/下一个天亮 - 郭静.flac","trackType":"flac"} Dec 15 16:54:50 volumio volumio[1137]: verbose: CURRENT POSITION 71 Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::syncState stateService play Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::syncState currentStatus play Dec 15 16:54:50 volumio volumio[1137]: info: Received an update from plugin. extracting info from payload Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:50 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:50 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:50 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:50 volumio volumio[1137]: info: ------------------------------ 41ms Dec 15 16:54:55 volumio volumio[1137]: info: CoreCommandRouter::volumioNext Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::next Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::stop Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::stPlaybackTimer Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::updateTrackBlock Dec 15 16:54:55 volumio volumio[1137]: info: CorePlayQueue::getTrackBlock Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:55 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:55 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 16:54:55 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::serviceStop Dec 15 16:54:55 volumio volumio[1137]: info: CorePlayQueue::getTrack 71 Dec 15 16:54:55 volumio volumio[1137]: info: CoreCommandRouter::serviceStop Dec 15 16:54:55 volumio volumio[1137]: info: ControllerMpd::stop Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand stop Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand stop took 14 milliseconds Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::play index undefined Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 16:54:55 volumio volumio[1137]: info: CorePlayQueue::getTrack 72 Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::startPlaybackTimer Dec 15 16:54:55 volumio volumio[1137]: info: CorePlayQueue::getTrack 72 Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::clearAddPlayTracks USB/86D5-4CBE/音乐/坏女孩 - 徐良&小凌.flac Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand stop Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::updateTrackBlock Dec 15 16:54:55 volumio volumio[1137]: info: CorePlayQueue::getTrackBlock Dec 15 16:54:55 volumio volumio[1137]: info: Dec 15 16:54:55 volumio volumio[1137]: ---------------------------- MPD announces state update: player Dec 15 16:54:55 volumio volumio[1137]: info: ControllerMpd::getState Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand status Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand stop took 3 milliseconds Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand clear Dec 15 16:54:55 volumio volumio[1137]: info: Dec 15 16:54:55 volumio volumio[1137]: ---------------------------- MPD announces system playlist update Dec 15 16:54:55 volumio volumio[1137]: info: Ignoring MPD Status Update Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand status took 2 milliseconds Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand clear took 1 milliseconds Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::parseState Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand add "USB/86D5-4CBE/音乐/坏女孩 - 徐良&小凌.flac" Dec 15 16:54:55 volumio volumio[1137]: error: updateQueue error: null Dec 15 16:54:55 volumio volumio[1137]: info: ------------------------------ 2ms Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::parseTrackInfo Dec 15 16:54:55 volumio volumio[1137]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Dec 15 16:54:55 volumio volumio[1137]: info: ------------------------------ 6ms Dec 15 16:54:55 volumio volumio[1137]: info: Dec 15 16:54:55 volumio volumio[1137]: ---------------------------- MPD announces system playlist update Dec 15 16:54:55 volumio volumio[1137]: info: Ignoring MPD Status Update Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand add "USB/86D5-4CBE/音乐/坏女孩 - 徐良&小凌.flac" took 3 milliseconds Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand play Dec 15 16:54:55 volumio volumio[1137]: info: ------------------------------ 2ms Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand play took 3 milliseconds Dec 15 16:54:55 volumio volumio[1137]: info: Dec 15 16:54:55 volumio volumio[1137]: ---------------------------- MPD announces state update: player Dec 15 16:54:55 volumio volumio[1137]: info: ControllerMpd::getState Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand status Dec 15 16:54:55 volumio volumio[1137]: info: Dec 15 16:54:55 volumio volumio[1137]: ---------------------------- MPD announces state update: player Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand status took 4 milliseconds Dec 15 16:54:55 volumio volumio[1137]: info: ControllerMpd::getState Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand status Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::parseState Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand status took 2 milliseconds Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::parseState Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::parseTrackInfo Dec 15 16:54:55 volumio volumio[1137]: info: ControllerMpd::pushState Dec 15 16:54:55 volumio volumio[1137]: info: CoreCommandRouter::servicePushState Dec 15 16:54:55 volumio volumio[1137]: info: CorePlayQueue::getTrack 72 Dec 15 16:54:55 volumio volumio[1137]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":247,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"坏女孩","artist":"徐良","album":"不良少年","uri":"USB/86D5-4CBE/音乐/坏女孩 - 徐良&小凌.flac","trackType":"flac"} Dec 15 16:54:55 volumio volumio[1137]: verbose: CURRENT POSITION 72 Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::syncState stateService play Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::syncState currentStatus stop Dec 15 16:54:55 volumio volumio[1137]: info: ------------------------------ 9ms Dec 15 16:54:55 volumio volumio[1137]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 15 16:54:55 volumio volumio[1137]: verbose: ControllerMpd::parseTrackInfo Dec 15 16:54:55 volumio volumio[1137]: info: ControllerMpd::pushState Dec 15 16:54:55 volumio volumio[1137]: info: CoreCommandRouter::servicePushState Dec 15 16:54:55 volumio volumio[1137]: info: CorePlayQueue::getTrack 72 Dec 15 16:54:55 volumio volumio[1137]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":247,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"坏女孩","artist":"徐良","album":"不良少年","uri":"USB/86D5-4CBE/音乐/坏女孩 - 徐良&小凌.flac","trackType":"flac"} Dec 15 16:54:55 volumio volumio[1137]: verbose: CURRENT POSITION 72 Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::syncState stateService play Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::syncState currentStatus play Dec 15 16:54:55 volumio volumio[1137]: info: Received an update from plugin. extracting info from payload Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:55 volumio volumio[1137]: info: CorePlayQueue::getTrack 72 Dec 15 16:54:55 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 16:54:55 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:55 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:55 volumio volumio[1137]: info: CorePlayQueue::getTrack 72 Dec 15 16:54:55 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:55 volumio volumio[1137]: info: ------------------------------ 39ms Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::volumioNext Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::next Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::stop Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::stPlaybackTimer Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::updateTrackBlock Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrackBlock Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 72 Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::serviceStop Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 72 Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::serviceStop Dec 15 16:54:59 volumio volumio[1137]: info: ControllerMpd::stop Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand stop Dec 15 16:54:59 volumio volumio[1137]: info: Dec 15 16:54:59 volumio volumio[1137]: ---------------------------- MPD announces state update: player Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand stop took 17 milliseconds Dec 15 16:54:59 volumio volumio[1137]: info: ControllerMpd::getState Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand status Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::play index undefined Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 73 Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::startPlaybackTimer Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 73 Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::clearAddPlayTracks USB/86D5-4CBE/音乐/世界赠予我的 - 王菲.flac Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand stop Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::updateTrackBlock Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrackBlock Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand status took 3 milliseconds Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand stop took 1 milliseconds Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::parseState Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand clear Dec 15 16:54:59 volumio volumio[1137]: info: Dec 15 16:54:59 volumio volumio[1137]: ---------------------------- MPD announces system playlist update Dec 15 16:54:59 volumio volumio[1137]: info: Ignoring MPD Status Update Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand clear took 1 milliseconds Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::parseTrackInfo Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand add "USB/86D5-4CBE/音乐/世界赠予我的 - 王菲.flac" Dec 15 16:54:59 volumio volumio[1137]: info: ControllerMpd::pushState Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::servicePushState Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 73 Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 73 Dec 15 16:54:59 volumio volumio[1137]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"坏女孩","artist":"徐良","album":"不良少年","uri":"USB/86D5-4CBE/音乐/坏女孩 - 徐良&小凌.flac","trackType":"flac"} Dec 15 16:54:59 volumio volumio[1137]: verbose: CURRENT POSITION 73 Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::syncState stateService stop Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::syncState currentStatus stop Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 73 Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:59 volumio volumio[1137]: info: No code Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 73 Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:59 volumio volumio[1137]: info: ------------------------------ 36ms Dec 15 16:54:59 volumio volumio[1137]: error: updateQueue error: null Dec 15 16:54:59 volumio volumio[1137]: info: Dec 15 16:54:59 volumio volumio[1137]: ---------------------------- MPD announces system playlist update Dec 15 16:54:59 volumio volumio[1137]: info: Ignoring MPD Status Update Dec 15 16:54:59 volumio volumio[1137]: info: ------------------------------ 33ms Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand add "USB/86D5-4CBE/音乐/世界赠予我的 - 王菲.flac" took 32 milliseconds Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand play Dec 15 16:54:59 volumio volumio[1137]: info: Dec 15 16:54:59 volumio volumio[1137]: ---------------------------- MPD announces state update: player Dec 15 16:54:59 volumio volumio[1137]: info: ------------------------------ 17ms Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand play took 17 milliseconds Dec 15 16:54:59 volumio volumio[1137]: info: ControllerMpd::getState Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand status Dec 15 16:54:59 volumio volumio[1137]: info: Dec 15 16:54:59 volumio volumio[1137]: ---------------------------- MPD announces state update: player Dec 15 16:54:59 volumio volumio[1137]: info: ControllerMpd::getState Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand status Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand status took 3 milliseconds Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::parseState Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand status took 7 milliseconds Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::parseState Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand playlistinfo took 7 milliseconds Dec 15 16:54:59 volumio volumio[1137]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::parseTrackInfo Dec 15 16:54:59 volumio volumio[1137]: verbose: ControllerMpd::parseTrackInfo Dec 15 16:54:59 volumio volumio[1137]: info: ControllerMpd::pushState Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::servicePushState Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 73 Dec 15 16:54:59 volumio volumio[1137]: verbose: STATE SERVICE {"status":"play","position":0,"seek":84,"duration":244,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"845 Kbps","isStreaming":false,"title":"世界赠与我的","artist":"王菲","album":"世界赠与我的","uri":"USB/86D5-4CBE/音乐/世界赠予我的 - 王菲.flac","trackType":"flac"} Dec 15 16:54:59 volumio volumio[1137]: verbose: CURRENT POSITION 73 Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::syncState stateService play Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::syncState currentStatus stop Dec 15 16:54:59 volumio volumio[1137]: info: ControllerMpd::pushState Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::servicePushState Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 73 Dec 15 16:54:59 volumio volumio[1137]: verbose: STATE SERVICE {"status":"play","position":0,"seek":273,"duration":244,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"963 Kbps","isStreaming":false,"title":"世界赠与我的","artist":"王菲","album":"世界赠与我的","uri":"USB/86D5-4CBE/音乐/世界赠予我的 - 王菲.flac","trackType":"flac"} Dec 15 16:54:59 volumio volumio[1137]: verbose: CURRENT POSITION 73 Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::syncState stateService play Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::syncState currentStatus play Dec 15 16:54:59 volumio volumio[1137]: info: Received an update from plugin. extracting info from payload Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 73 Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:59 volumio volumio[1137]: info: CoreStateMachine::pushState Dec 15 16:54:59 volumio volumio[1137]: info: CorePlayQueue::getTrack 73 Dec 15 16:54:59 volumio volumio[1137]: info: CoreCommandRouter::volumioPushState Dec 15 16:54:59 volumio volumio[1137]: info: ------------------------------ 26ms Dec 15 16:54:59 volumio volumio[1137]: info: ------------------------------ 43ms Dec 15 16:55:21 volumio volumio[1137]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 16:55:21 volumio volumio[1137]: Error: connect ENETUNREACH 199.59.148.9:443 Dec 15 16:55:21 volumio volumio[1137]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 16:55:21 volumio volumio[1137]: errno: -101, Dec 15 16:55:21 volumio volumio[1137]: code: 'ENETUNREACH', Dec 15 16:55:21 volumio volumio[1137]: syscall: 'connect', Dec 15 16:55:21 volumio volumio[1137]: address: '199.59.148.9', Dec 15 16:55:21 volumio volumio[1137]: port: 443 Dec 15 16:55:21 volumio volumio[1137]: } Dec 15 16:55:21 volumio volumio[1137]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 16:55:22 volumio sudo[6941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 16:54' Dec 15 16:55:22 volumio sudo[6941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"