-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Fri 2025-05-02 11:14:31 CEST. -- May 02 11:13:00 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:00 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:02 volumio volumio[922]: info: CoreCommandRouter::getUIConfigOnPlugin May 02 11:13:02 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 02 11:13:02 volumio volumio[922]: info: Executing endpoint metavolumio May 02 11:13:02 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 02 11:13:02 volumio volumio[922]: info: Executing endpoint metavolumio May 02 11:13:02 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 02 11:13:02 volumio volumio[922]: info: Executing endpoint metavolumio May 02 11:13:02 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 02 11:13:03 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork May 02 11:13:03 volumio sudo[9394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 May 02 11:13:03 volumio sudo[9394]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:03 volumio sudo[9394]: pam_unix(sudo:session): session closed for user root May 02 11:13:03 volumio sudo[9401]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 May 02 11:13:03 volumio sudo[9401]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:03 volumio sudo[9401]: pam_unix(sudo:session): session closed for user root May 02 11:13:03 volumio sudo[9408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 May 02 11:13:03 volumio sudo[9408]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:03 volumio sudo[9408]: pam_unix(sudo:session): session closed for user root May 02 11:13:03 volumio sudo[9414]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 May 02 11:13:03 volumio sudo[9414]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:03 volumio sudo[9414]: pam_unix(sudo:session): session closed for user root May 02 11:13:03 volumio sudo[9420]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 11:13:03 volumio sudo[9420]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:03 volumio sudo[9420]: pam_unix(sudo:session): session closed for user root May 02 11:13:03 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache May 02 11:13:03 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks May 02 11:13:03 volumio sudo[9423]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 11:13:03 volumio sudo[9423]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:03 volumio sudo[9423]: pam_unix(sudo:session): session closed for user root May 02 11:13:03 volumio sudo[9426]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 02 11:13:03 volumio sudo[9426]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:05 volumio volumio[922]: error: Failed request for metavolumio API May 02 11:13:07 volumio sudo[9426]: pam_unix(sudo:session): session closed for user root May 02 11:13:11 volumio volumio[922]: info: CALLMETHOD: system_controller network saveWirelessNet [object Object] May 02 11:13:11 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNet May 02 11:13:11 volumio sudo[9446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/network/interfaces May 02 11:13:11 volumio sudo[9446]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:11 volumio sudo[9446]: pam_unix(sudo:session): session closed for user root May 02 11:13:11 volumio sudo[9448]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/dhcpcd.conf May 02 11:13:11 volumio sudo[9448]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:11 volumio sudo[9448]: pam_unix(sudo:session): session closed for user root May 02 11:13:11 volumio volumio[922]: info: Permissions for /etc/network/interfaces set May 02 11:13:11 volumio volumio[922]: info: Restarting Wireless Network May 02 11:13:11 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart May 02 11:13:11 volumio volumio[922]: info: Discovery: Restarting Advertising due to device name change May 02 11:13:11 volumio sudo[9451]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service May 02 11:13:11 volumio sudo[9451]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:11 volumio systemd[1]: wireless.service: Killing process 2689 (wpa_supplicant) with signal SIGKILL. May 02 11:13:11 volumio systemd[1]: wireless.service: Killing process 2729 (dhcpcd) with signal SIGKILL. May 02 11:13:11 volumio systemd[1]: Stopping Wireless Services... May 02 11:13:11 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:13:11 volumio systemd[1]: wireless.service: Succeeded. May 02 11:13:11 volumio systemd[1]: Stopped Wireless Services. May 02 11:13:11 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 02 11:13:11 volumio systemd[1]: Starting Wireless Services... May 02 11:13:11 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:13:12 volumio wireless.js[9453]: Cleaning previous... May 02 11:13:12 volumio sudo[9470]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 02 11:13:12 volumio sudo[9470]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:12 volumio avahi-daemon[628]: Withdrawing address record for 192.168.1.62 on wlan0. May 02 11:13:12 volumio avahi-daemon[628]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.62. May 02 11:13:12 volumio avahi-daemon[628]: Interface wlan0.IPv4 no longer relevant for mDNS. May 02 11:13:12 volumio sudo[9470]: pam_unix(sudo:session): session closed for user root May 02 11:13:12 volumio volumio[922]: info: Discovery: A device disappeared from network May 02 11:13:12 volumio volumio[922]: info: Discovery: Device volumio disappeared from network May 02 11:13:12 volumio sudo[9472]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down May 02 11:13:12 volumio sudo[9472]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:12 volumio volumio[922]: info: Discovery: A device disappeared from network May 02 11:13:12 volumio sudo[9472]: pam_unix(sudo:session): session closed for user root May 02 11:13:12 volumio wireless.js[9453]: Stopped aP May 02 11:13:12 volumio sudo[9479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 02 11:13:12 volumio sudo[9479]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:12 volumio sudo[9479]: pam_unix(sudo:session): session closed for user root May 02 11:13:12 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 02 11:13:12 volumio sudo[9481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get May 02 11:13:12 volumio sudo[9481]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:12 volumio sudo[9481]: pam_unix(sudo:session): session closed for user root May 02 11:13:12 volumio sudo[9489]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 02 11:13:12 volumio sudo[9489]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:12 volumio sudo[9489]: pam_unix(sudo:session): session closed for user root May 02 11:13:12 volumio sudo[9491]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan May 02 11:13:12 volumio sudo[9491]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:14 volumio ntpd[779]: Deleting interface #6 wlan0, 192.168.1.62#123, interface stats: received=87, sent=101, dropped=0, active_time=2135 secs May 02 11:13:14 volumio ntpd[779]: 194.182.77.109 local addr 192.168.1.62 -> May 02 11:13:14 volumio ntpd[779]: 185.47.221.82 local addr 192.168.1.62 -> May 02 11:13:14 volumio ntpd[779]: 147.251.48.140 local addr 192.168.1.62 -> May 02 11:13:14 volumio ntpd[779]: 162.159.200.123 local addr 192.168.1.62 -> May 02 11:13:14 volumio ntpd[779]: 78.108.102.237 local addr 192.168.1.62 -> May 02 11:13:14 volumio ntpd[779]: 78.108.96.197 local addr 192.168.1.62 -> May 02 11:13:14 volumio ntpd[779]: 78.80.37.86 local addr 192.168.1.62 -> May 02 11:13:14 volumio ntpd[779]: 80.211.220.41 local addr 192.168.1.62 -> May 02 11:13:14 volumio ntpd[779]: 5.1.56.123 local addr 192.168.1.62 -> May 02 11:13:14 volumio ntpd[779]: 93.99.104.53 local addr 192.168.1.62 -> May 02 11:13:14 volumio ntpd[779]: 89.203.251.72 local addr 192.168.1.62 -> May 02 11:13:15 volumio sudo[9491]: pam_unix(sudo:session): session closed for user root May 02 11:13:15 volumio wireless.js[9453]: SETTING APPROPRIATE REG DOMAIN: DE May 02 11:13:15 volumio sudo[9497]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 02 11:13:15 volumio sudo[9497]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:15 volumio sudo[9497]: pam_unix(sudo:session): session closed for user root May 02 11:13:15 volumio sudo[9499]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE May 02 11:13:15 volumio sudo[9499]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:15 volumio sudo[9499]: pam_unix(sudo:session): session closed for user root May 02 11:13:15 volumio wireless.js[9453]: SUCCESSFULLY SET NEW REGDOMAIN: DE May 02 11:13:15 volumio wireless.js[9453]: Start wireless flow May 02 11:13:15 volumio wireless.js[9453]: Stopped hotspot (if there).. May 02 11:13:15 volumio sudo[9504]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 02 11:13:15 volumio sudo[9504]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:15 volumio sudo[9504]: pam_unix(sudo:session): session closed for user root May 02 11:13:15 volumio sudo[9506]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down May 02 11:13:15 volumio sudo[9506]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:15 volumio sudo[9506]: pam_unix(sudo:session): session closed for user root May 02 11:13:15 volumio wireless.js[9453]: DHCP IP May 02 11:13:15 volumio wireless.js[9453]: Start ap May 02 11:13:15 volumio wpa_supplicant[9508]: Successfully initialized wpa_supplicant May 02 11:13:15 volumio sudo[9509]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd May 02 11:13:15 volumio sudo[9509]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:15 volumio dhcpcd[9510]: main: control_open: Connection refused May 02 11:13:15 volumio dhcpcd[9510]: dev: loaded udev May 02 11:13:15 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 02 11:13:15 volumio dhcpcd-run-hooks[9519]: wlan0: starting wpa_supplicant May 02 11:13:16 volumio dhcpcd-run-hooks[9524]: wlan0: failed to start wpa_supplicant May 02 11:13:16 volumio dhcpcd-run-hooks[9525]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma May 02 11:13:16 volumio dhcpcd[9510]: wlan0: connected to Access Point `' May 02 11:13:16 volumio dhcpcd[9510]: DUID 00:01:00:01:2f:9c:a7:37:e4:5f:01:a8:52:d9 May 02 11:13:16 volumio dhcpcd[9510]: eth0: IAID 01:a8:52:d9 May 02 11:13:16 volumio dhcpcd[9510]: eth0: adding address fe80::e65f:1ff:fea8:52d9 May 02 11:13:16 volumio dhcpcd[9510]: ipv6_addaddr1: Permission denied May 02 11:13:16 volumio dhcpcd[9510]: wlan0: waiting for carrier May 02 11:13:16 volumio volumio[922]: info: Discovery: Started advertising with name: Volumio May 02 11:13:16 volumio dhcpcd[9510]: eth0: soliciting an IPv6 router May 02 11:13:16 volumio dhcpcd[9510]: eth0: rebinding lease of 192.168.1.61 May 02 11:13:16 volumio dhcpcd[9510]: eth0: NAK: address in use from 192.168.1.20 May 02 11:13:16 volumio dhcpcd[9510]: eth0: message: address in use May 02 11:13:16 volumio wireless.js[9453]: trying... May 02 11:13:16 volumio dhcpcd[1174]: eth0: pid -1952327586 deleted IP address 192.168.1.61/24 May 02 11:13:16 volumio dhcpcd[1174]: eth0: deleting route to 192.168.1.0/24 May 02 11:13:16 volumio dhcpcd[1174]: eth0: deleting default route via 192.168.1.20 May 02 11:13:16 volumio avahi-daemon[628]: Withdrawing address record for 192.168.1.61 on eth0. May 02 11:13:16 volumio avahi-daemon[628]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.61. May 02 11:13:16 volumio avahi-daemon[628]: Interface eth0.IPv4 no longer relevant for mDNS. May 02 11:13:16 volumio sudo[9545]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:16 volumio sudo[9545]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:16 volumio sudo[9545]: pam_unix(sudo:session): session closed for user root May 02 11:13:16 volumio dnsmasq[913]: reading /etc/resolv.conf May 02 11:13:16 volumio dnsmasq[913]: using nameserver 192.168.1.20#53 May 02 11:13:16 volumio dnsmasq[913]: using nameserver 192.168.1.20#53 May 02 11:13:16 volumio dnsmasq[913]: using nameserver 208.67.222.222#53 May 02 11:13:16 volumio dnsmasq[913]: using nameserver 208.67.220.220#53 May 02 11:13:16 volumio dnsmasq[913]: using nameserver 208.67.222.222#53 May 02 11:13:16 volumio dnsmasq[913]: using nameserver 208.67.220.220#53 May 02 11:13:16 volumio dhcpcd[1174]: eth0: rebinding lease of 192.168.1.61 May 02 11:13:16 volumio dhcpcd[9510]: eth0: soliciting a DHCP lease May 02 11:13:16 volumio dhcpcd[1174]: eth0: probing address 192.168.1.61/24 May 02 11:13:17 volumio wireless.js[9453]: trying... May 02 11:13:17 volumio sudo[9588]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:17 volumio sudo[9588]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:17 volumio sudo[9588]: pam_unix(sudo:session): session closed for user root May 02 11:13:18 volumio ntpd[779]: Deleting interface #8 eth0, 192.168.1.61#123, interface stats: received=50, sent=51, dropped=3, active_time=285 secs May 02 11:13:18 volumio ntpd[779]: 194.182.77.109 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 185.47.221.82 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 147.251.48.140 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 162.159.200.123 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 78.108.102.237 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 78.108.96.197 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 78.80.37.86 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 80.211.220.41 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 5.1.56.123 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 93.99.104.53 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 89.203.251.72 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 195.58.34.65 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 81.0.208.219 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 194.87.253.15 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 92.62.231.58 local addr 192.168.1.61 -> May 02 11:13:18 volumio ntpd[779]: 195.58.34.161 local addr 192.168.1.61 -> May 02 11:13:18 volumio wireless.js[9453]: trying... May 02 11:13:18 volumio sudo[9591]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:18 volumio sudo[9591]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:18 volumio sudo[9591]: pam_unix(sudo:session): session closed for user root May 02 11:13:19 volumio wireless.js[9453]: trying... May 02 11:13:19 volumio sudo[9594]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:19 volumio sudo[9594]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:19 volumio sudo[9594]: pam_unix(sudo:session): session closed for user root May 02 11:13:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 May 02 11:13:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 May 02 11:13:20 volumio dhcpcd[9510]: eth0: offered 192.168.1.63 from 192.168.1.20 May 02 11:13:20 volumio dhcpcd[9510]: eth0: ignoring offer of 192.168.1.63 from 192.168.1.20 May 02 11:13:20 volumio dhcpcd[9510]: eth0: probing address 192.168.1.63/24 May 02 11:13:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 May 02 11:13:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 May 02 11:13:20 volumio volumio[922]: info: Volumio Network Manager: Network status updated: 0 May 02 11:13:20 volumio wireless.js[9453]: trying... May 02 11:13:20 volumio sudo[9611]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:20 volumio sudo[9611]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:20 volumio sudo[9611]: pam_unix(sudo:session): session closed for user root May 02 11:13:21 volumio dhcpcd[1174]: eth0: leased 192.168.1.61 for 600 seconds May 02 11:13:21 volumio dhcpcd[1174]: eth0: adding route to 192.168.1.0/24 May 02 11:13:21 volumio avahi-daemon[628]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.61. May 02 11:13:21 volumio dhcpcd[1174]: eth0: adding default route via 192.168.1.20 May 02 11:13:21 volumio avahi-daemon[628]: New relevant interface eth0.IPv4 for mDNS. May 02 11:13:21 volumio avahi-daemon[628]: Registering new address record for 192.168.1.61 on eth0.IPv4. May 02 11:13:21 volumio dnsmasq[913]: reading /etc/resolv.conf May 02 11:13:21 volumio dnsmasq[913]: using nameserver 192.168.1.20#53 May 02 11:13:21 volumio dnsmasq[913]: using nameserver 208.67.222.222#53 May 02 11:13:21 volumio dnsmasq[913]: using nameserver 208.67.220.220#53 May 02 11:13:21 volumio wireless.js[9453]: trying... May 02 11:13:21 volumio sudo[9636]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:21 volumio sudo[9636]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:21 volumio sudo[9636]: pam_unix(sudo:session): session closed for user root May 02 11:13:22 volumio wpa_supplicant[9523]: wlan0: Trying to associate with SSID 'ANTONIN_5_EXT' May 02 11:13:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 May 02 11:13:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 May 02 11:13:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 May 02 11:13:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 May 02 11:13:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 May 02 11:13:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 May 02 11:13:22 volumio dhcpcd[9510]: wlan0: carrier acquired May 02 11:13:22 volumio dhcpcd[9510]: wlan0: connected to Access Point `ANTONIN_5_EXT' May 02 11:13:22 volumio wpa_supplicant[9523]: wlan0: Associated with 50:91:e3:99:b4:9b May 02 11:13:22 volumio wpa_supplicant[9523]: wlan0: CTRL-EVENT-CONNECTED - Connection to 50:91:e3:99:b4:9b completed [id=0 id_str=] May 02 11:13:22 volumio wpa_supplicant[9523]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 02 11:13:22 volumio wpa_supplicant[9523]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE May 02 11:13:22 volumio dhcpcd[9510]: wlan0: IAID 01:a8:52:da May 02 11:13:22 volumio dhcpcd[9510]: wlan0: adding address fe80::e65f:1ff:fea8:52da May 02 11:13:22 volumio dhcpcd[9510]: ipv6_addaddr1: Permission denied May 02 11:13:22 volumio dhcpcd[9510]: wlan0: carrier lost May 02 11:13:22 volumio dhcpcd[9510]: wlan0: carrier acquired May 02 11:13:22 volumio dhcpcd[9510]: wlan0: IAID 01:a8:52:da May 02 11:13:22 volumio dhcpcd[9510]: wlan0: soliciting an IPv6 router May 02 11:13:22 volumio wireless.js[9453]: trying... May 02 11:13:22 volumio sudo[9658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:22 volumio sudo[9658]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:22 volumio sudo[9658]: pam_unix(sudo:session): session closed for user root May 02 11:13:22 volumio dhcpcd[9510]: wlan0: rebinding lease of 192.168.1.62 May 02 11:13:23 volumio dhcpcd[9510]: wlan0: NAK: address in use from 192.168.1.20 May 02 11:13:23 volumio dhcpcd[9510]: wlan0: message: address in use May 02 11:13:23 volumio dnsmasq[913]: reading /etc/resolv.conf May 02 11:13:23 volumio dnsmasq[913]: using nameserver 192.168.1.20#53 May 02 11:13:23 volumio dnsmasq[913]: using nameserver 208.67.222.222#53 May 02 11:13:23 volumio dnsmasq[913]: using nameserver 208.67.220.220#53 May 02 11:13:23 volumio dhcpcd[9510]: wlan0: soliciting a DHCP lease May 02 11:13:23 volumio wireless.js[9453]: trying... May 02 11:13:23 volumio sudo[9681]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:23 volumio sudo[9681]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:23 volumio sudo[9681]: pam_unix(sudo:session): session closed for user root May 02 11:13:24 volumio ntpd[779]: Listen normally on 9 eth0 192.168.1.61:123 May 02 11:13:24 volumio ntpd[779]: new interface(s) found: waking up resolver May 02 11:13:24 volumio volumio[922]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.117 UA: Mozilla/5.0 (Linux; Android 10; Lenovo TB-8505F Build/QP1A.190711.020; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.100 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 May 02 11:13:24 volumio volumio[922]: info: Received Get System Info May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 11:13:24 volumio volumio[922]: info: Discovery: Getting this device information May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:24 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:24 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::volumioGetVisibleSources May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:24 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 02 11:13:24 volumio volumio[922]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 02 11:13:24 volumio volumio[922]: info: Received Get System Info May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 11:13:24 volumio volumio[922]: info: Discovery: Getting this device information May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:24 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:24 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:24 volumio volumio[922]: info: Listing playlists May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::volumioGetQueue May 02 11:13:24 volumio volumio[922]: info: CoreStateMachine::getQueue May 02 11:13:24 volumio volumio[922]: info: CorePlayQueue::getQueue May 02 11:13:24 volumio wireless.js[9453]: trying... May 02 11:13:24 volumio sudo[9684]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:24 volumio sudo[9684]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:24 volumio sudo[9684]: pam_unix(sudo:session): session closed for user root May 02 11:13:24 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 02 11:13:25 volumio wireless.js[9453]: trying... May 02 11:13:25 volumio sudo[9687]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:25 volumio sudo[9687]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:25 volumio sudo[9687]: pam_unix(sudo:session): session closed for user root May 02 11:13:26 volumio dhcpcd[9510]: eth0: leased 192.168.1.63 for 600 seconds May 02 11:13:26 volumio dhcpcd[9510]: eth0: adding route to 192.168.1.0/24 May 02 11:13:26 volumio dhcpcd[9510]: eth0: adding default route via 192.168.1.20 May 02 11:13:26 volumio avahi-daemon[628]: Registering new address record for 192.168.1.63 on eth0.IPv4. May 02 11:13:26 volumio dhcpcd[9510]: forked to background, child pid 9709 May 02 11:13:26 volumio sudo[9509]: pam_unix(sudo:session): session closed for user root May 02 11:13:26 volumio dhcpcd[9709]: wlan0: offered 192.168.1.64 from 192.168.1.20 May 02 11:13:26 volumio dhcpcd[9709]: wlan0: probing address 192.168.1.64/24 May 02 11:13:26 volumio volumio[922]: info: Discovery: Browse raised the following error Error: dns service error: unknown May 02 11:13:26 volumio wireless.js[9453]: trying... May 02 11:13:26 volumio sudo[9711]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:26 volumio sudo[9711]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:26 volumio sudo[9711]: pam_unix(sudo:session): session closed for user root May 02 11:13:27 volumio ntpd[779]: Listen normally on 10 eth0 192.168.1.63:123 May 02 11:13:27 volumio ntpd[779]: new interface(s) found: waking up resolver May 02 11:13:27 volumio wireless.js[9453]: trying... May 02 11:13:27 volumio sudo[9714]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:27 volumio sudo[9714]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:27 volumio sudo[9714]: pam_unix(sudo:session): session closed for user root May 02 11:13:28 volumio volumio[922]: info: CALLMETHOD: system_controller network saveDnsSettings [object Object] May 02 11:13:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , saveDnsSettings May 02 11:13:28 volumio sudo[9717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/resolv.conf.tail May 02 11:13:28 volumio sudo[9717]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:28 volumio sudo[9717]: pam_unix(sudo:session): session closed for user root May 02 11:13:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart May 02 11:13:28 volumio volumio[922]: info: Discovery: Restarting Advertising due to device name change May 02 11:13:28 volumio sudo[9720]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service May 02 11:13:28 volumio sudo[9720]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart May 02 11:13:28 volumio volumio[922]: info: Discovery: Restarting Advertising due to device name change May 02 11:13:28 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 02 11:13:28 volumio systemd[1]: wireless.service: Control process exited, code=killed, status=15/TERM May 02 11:13:28 volumio systemd[1]: wireless.service: Killing process 9523 (wpa_supplicant) with signal SIGKILL. May 02 11:13:28 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:13:28 volumio systemd[1]: wireless.service: Killing process 9709 (dhcpcd) with signal SIGKILL. May 02 11:13:28 volumio sudo[9723]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ip addr flush dev eth0 May 02 11:13:28 volumio sudo[9723]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:28 volumio dhcpcd[1174]: eth0: pid 9724 deleted IP address 192.168.1.61/24 May 02 11:13:28 volumio dhcpcd[1174]: eth0: deleting route to 192.168.1.0/24 May 02 11:13:28 volumio dhcpcd[1174]: eth0: deleting default route via 192.168.1.20 May 02 11:13:28 volumio sudo[9723]: pam_unix(sudo:session): session closed for user root May 02 11:13:28 volumio avahi-daemon[628]: Withdrawing address record for 192.168.1.61 on eth0. May 02 11:13:28 volumio avahi-daemon[628]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.61. May 02 11:13:28 volumio avahi-daemon[628]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.63. May 02 11:13:28 volumio avahi-daemon[628]: Withdrawing address record for 192.168.1.63 on eth0. May 02 11:13:28 volumio avahi-daemon[628]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.63. May 02 11:13:28 volumio avahi-daemon[628]: Interface eth0.IPv4 no longer relevant for mDNS. May 02 11:13:28 volumio volumio[922]: info: Discovery: A device disappeared from network May 02 11:13:28 volumio dnsmasq[913]: reading /etc/resolv.conf May 02 11:13:28 volumio dnsmasq[913]: using nameserver 208.67.222.222#53 May 02 11:13:28 volumio dnsmasq[913]: using nameserver 208.67.220.220#53 May 02 11:13:28 volumio sudo[9726]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 down May 02 11:13:28 volumio sudo[9726]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:28 volumio systemd[1]: wireless.service: Succeeded. May 02 11:13:28 volumio systemd[1]: Stopped Wireless Services. May 02 11:13:28 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 02 11:13:28 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down May 02 11:13:28 volumio systemd[1]: Starting Wireless Services... May 02 11:13:28 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:13:28 volumio sudo[9726]: pam_unix(sudo:session): session closed for user root May 02 11:13:28 volumio dhcpcd[1174]: eth0: rebinding lease of 192.168.1.63 May 02 11:13:28 volumio dhcpcd[1174]: arp_announce1: Network is down May 02 11:13:28 volumio dhcpcd[1174]: eth0: bpf_send: Network is down May 02 11:13:28 volumio dhcpcd[1174]: dhcp_readbpf: eth0: Network is down May 02 11:13:28 volumio dhcpcd[1174]: arp_read: eth0: Network is down May 02 11:13:28 volumio ifplugd(eth0)[787]: Link beat lost. May 02 11:13:28 volumio dhcpcd[1174]: eth0: pid 9724 deleted IP address 192.168.1.63/24 May 02 11:13:28 volumio kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) May 02 11:13:28 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down May 02 11:13:28 volumio sudo[9749]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 up May 02 11:13:28 volumio sudo[9749]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:28 volumio sudo[9749]: pam_unix(sudo:session): session closed for user root May 02 11:13:28 volumio dhcpcd[1174]: eth0: rebinding lease of 192.168.1.63 May 02 11:13:28 volumio dhcpcd[1174]: eth0: carrier lost May 02 11:13:29 volumio wireless.js[9740]: Cleaning previous... May 02 11:13:29 volumio sudo[9786]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 02 11:13:29 volumio sudo[9786]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:29 volumio sudo[9786]: pam_unix(sudo:session): session closed for user root May 02 11:13:29 volumio sudo[9788]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down May 02 11:13:29 volumio sudo[9788]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:29 volumio sudo[9788]: pam_unix(sudo:session): session closed for user root May 02 11:13:29 volumio wireless.js[9740]: Stopped aP May 02 11:13:29 volumio sudo[9795]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 02 11:13:29 volumio sudo[9795]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:29 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 02 11:13:29 volumio sudo[9795]: pam_unix(sudo:session): session closed for user root May 02 11:13:29 volumio sudo[9797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get May 02 11:13:29 volumio sudo[9797]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:29 volumio sudo[9797]: pam_unix(sudo:session): session closed for user root May 02 11:13:29 volumio sudo[9804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 02 11:13:29 volumio sudo[9804]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:29 volumio sudo[9804]: pam_unix(sudo:session): session closed for user root May 02 11:13:29 volumio sudo[9806]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan May 02 11:13:29 volumio sudo[9806]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:30 volumio dhcpcd[1174]: eth0: carrier acquired May 02 11:13:30 volumio dhcpcd[1174]: eth0: confile file changed, expiring leases May 02 11:13:30 volumio dhcpcd[1174]: eth0: IAID 01:a8:52:d9 May 02 11:13:30 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx May 02 11:13:30 volumio ifplugd(eth0)[787]: Link beat detected. May 02 11:13:31 volumio dhcpcd[1174]: eth0: rebinding lease of 192.168.1.63 May 02 11:13:31 volumio dhcpcd[1174]: eth0: probing address 192.168.1.63/24 May 02 11:13:31 volumio dhcpcd[1174]: eth0: soliciting an IPv6 router May 02 11:13:32 volumio ntpd[779]: Deleting interface #9 eth0, 192.168.1.61#123, interface stats: received=14, sent=15, dropped=12, active_time=8 secs May 02 11:13:32 volumio ntpd[779]: 194.182.77.109 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 185.47.221.82 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 147.251.48.140 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 162.159.200.123 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 78.108.102.237 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 78.108.96.197 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 78.80.37.86 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 80.211.220.41 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 5.1.56.123 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 93.99.104.53 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 89.203.251.72 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 195.58.34.161 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 92.62.231.58 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 194.87.253.15 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 81.0.208.219 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: 195.58.34.65 local addr 192.168.1.61 -> May 02 11:13:32 volumio ntpd[779]: Deleting interface #10 eth0, 192.168.1.63#123, interface stats: received=0, sent=0, dropped=0, active_time=5 secs May 02 11:13:32 volumio sudo[9806]: pam_unix(sudo:session): session closed for user root May 02 11:13:32 volumio wireless.js[9740]: SETTING APPROPRIATE REG DOMAIN: DE May 02 11:13:32 volumio sudo[9826]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 02 11:13:32 volumio sudo[9826]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:32 volumio sudo[9826]: pam_unix(sudo:session): session closed for user root May 02 11:13:32 volumio sudo[9828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE May 02 11:13:32 volumio sudo[9828]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:32 volumio sudo[9828]: pam_unix(sudo:session): session closed for user root May 02 11:13:32 volumio wireless.js[9740]: SUCCESSFULLY SET NEW REGDOMAIN: DE May 02 11:13:32 volumio wireless.js[9740]: Start wireless flow May 02 11:13:32 volumio wireless.js[9740]: Stopped hotspot (if there).. May 02 11:13:32 volumio sudo[9833]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 May 02 11:13:32 volumio sudo[9833]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:32 volumio sudo[9833]: pam_unix(sudo:session): session closed for user root May 02 11:13:32 volumio sudo[9835]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down May 02 11:13:32 volumio sudo[9835]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:32 volumio sudo[9835]: pam_unix(sudo:session): session closed for user root May 02 11:13:32 volumio wireless.js[9740]: DHCP IP May 02 11:13:32 volumio wireless.js[9740]: Start ap May 02 11:13:32 volumio wpa_supplicant[9837]: Successfully initialized wpa_supplicant May 02 11:13:32 volumio sudo[9838]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd May 02 11:13:33 volumio sudo[9838]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:33 volumio dhcpcd[9839]: main: control_open: Connection refused May 02 11:13:33 volumio dhcpcd[9839]: dev: loaded udev May 02 11:13:33 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 02 11:13:33 volumio dhcpcd-run-hooks[9848]: wlan0: starting wpa_supplicant May 02 11:13:33 volumio dhcpcd-run-hooks[9853]: wlan0: failed to start wpa_supplicant May 02 11:13:33 volumio dhcpcd-run-hooks[9854]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma May 02 11:13:33 volumio dhcpcd[9839]: wlan0: connected to Access Point `' May 02 11:13:33 volumio dhcpcd[9839]: DUID 00:01:00:01:2f:9c:a7:37:e4:5f:01:a8:52:d9 May 02 11:13:33 volumio dhcpcd[9839]: eth0: IAID 01:a8:52:d9 May 02 11:13:33 volumio dhcpcd[9839]: eth0: adding address fe80::e65f:1ff:fea8:52d9 May 02 11:13:33 volumio dhcpcd[9839]: ipv6_addaddr1: Permission denied May 02 11:13:33 volumio dhcpcd[9839]: wlan0: waiting for carrier May 02 11:13:33 volumio dhcpcd[9839]: eth0: soliciting an IPv6 router May 02 11:13:33 volumio volumio[922]: info: Discovery: Started advertising with name: Volumio May 02 11:13:33 volumio volumio[922]: info: Discovery: Started advertising with name: Volumio May 02 11:13:33 volumio dhcpcd[9839]: eth0: rebinding lease of 192.168.1.63 May 02 11:13:33 volumio dhcpcd[9839]: eth0: probing address 192.168.1.63/24 May 02 11:13:33 volumio wireless.js[9740]: trying... May 02 11:13:34 volumio sudo[9867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:34 volumio sudo[9867]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:34 volumio sudo[9867]: pam_unix(sudo:session): session closed for user root May 02 11:13:34 volumio wireless.js[9740]: trying... May 02 11:13:35 volumio sudo[9871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:35 volumio sudo[9871]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:35 volumio sudo[9871]: pam_unix(sudo:session): session closed for user root May 02 11:13:35 volumio wireless.js[9740]: trying... May 02 11:13:36 volumio sudo[9874]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:36 volumio sudo[9874]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:36 volumio sudo[9874]: pam_unix(sudo:session): session closed for user root May 02 11:13:36 volumio wireless.js[9740]: trying... May 02 11:13:37 volumio sudo[9877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:37 volumio sudo[9877]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:37 volumio sudo[9877]: pam_unix(sudo:session): session closed for user root May 02 11:13:37 volumio dhcpcd[1174]: eth0: leased 192.168.1.63 for 600 seconds May 02 11:13:37 volumio avahi-daemon[628]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.63. May 02 11:13:37 volumio dhcpcd[1174]: eth0: adding route to 192.168.1.0/24 May 02 11:13:37 volumio avahi-daemon[628]: New relevant interface eth0.IPv4 for mDNS. May 02 11:13:37 volumio dhcpcd[1174]: eth0: adding default route via 192.168.1.20 May 02 11:13:37 volumio avahi-daemon[628]: Registering new address record for 192.168.1.63 on eth0.IPv4. May 02 11:13:37 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 May 02 11:13:37 volumio dnsmasq[913]: reading /etc/resolv.conf May 02 11:13:37 volumio dnsmasq[913]: using nameserver 208.67.222.222#53 May 02 11:13:37 volumio dnsmasq[913]: using nameserver 208.67.220.220#53 May 02 11:13:37 volumio dnsmasq[913]: using nameserver 192.168.1.20#53 May 02 11:13:37 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 May 02 11:13:37 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 May 02 11:13:37 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 May 02 11:13:37 volumio wireless.js[9740]: trying... May 02 11:13:38 volumio sudo[9901]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:38 volumio sudo[9901]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:38 volumio sudo[9901]: pam_unix(sudo:session): session closed for user root May 02 11:13:38 volumio volumio[922]: info: Discovery: adding 2c0b382c-19eb-499d-9e5b-25e5ae31cd9e May 02 11:13:38 volumio volumio[922]: info: Discovery: Found device Volumio May 02 11:13:38 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:38 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:38 volumio ntpd[779]: Listen normally on 11 eth0 192.168.1.63:123 May 02 11:13:38 volumio ntpd[779]: new interface(s) found: waking up resolver May 02 11:13:38 volumio dhcpcd[9839]: eth0: leased 192.168.1.63 for 600 seconds May 02 11:13:38 volumio dhcpcd[9839]: eth0: adding route to 192.168.1.0/24 May 02 11:13:38 volumio dhcpcd[9839]: eth0: adding default route via 192.168.1.20 May 02 11:13:38 volumio dhcpcd[9839]: forked to background, child pid 9922 May 02 11:13:38 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart May 02 11:13:38 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart May 02 11:13:38 volumio volumio[922]: info: Refreshing Cached IP Addresses May 02 11:13:38 volumio sudo[9838]: pam_unix(sudo:session): session closed for user root May 02 11:13:38 volumio sudo[9924]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli May 02 11:13:38 volumio sudo[9924]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:38 volumio sudo[9924]: pam_unix(sudo:session): session closed for user root May 02 11:13:38 volumio sudo[9927]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 11:13:38 volumio sudo[9927]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:38 volumio sudo[9927]: pam_unix(sudo:session): session closed for user root May 02 11:13:38 volumio volumio[922]: error: Upnp client error: Error: This socket has been ended by the other party May 02 11:13:38 volumio sudo[9930]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 11:13:38 volumio sudo[9930]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:38 volumio sudo[9930]: pam_unix(sudo:session): session closed for user root May 02 11:13:38 volumio wireless.js[9740]: trying... May 02 11:13:39 volumio sudo[9933]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:39 volumio sudo[9933]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:39 volumio sudo[9933]: pam_unix(sudo:session): session closed for user root May 02 11:13:39 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 11:13:39 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 11:13:39 volumio volumio[922]: info: Discovery: Getting this device information May 02 11:13:39 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:39 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:39 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 11:13:39 volumio volumio[922]: verbose: New Socket.io Connection to 192.168.1.63:3000 from 192.168.1.117 UA: Dart/3.7 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 May 02 11:13:39 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:39 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:39 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 02 11:13:39 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 02 11:13:39 volumio wpa_supplicant[9852]: wlan0: Trying to associate with SSID 'ANTONIN_5_EXT' May 02 11:13:39 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 May 02 11:13:39 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 May 02 11:13:39 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 May 02 11:13:39 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 May 02 11:13:39 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 May 02 11:13:39 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 May 02 11:13:39 volumio wpa_supplicant[9852]: wlan0: Associated with 50:91:e3:99:b4:9b May 02 11:13:39 volumio wpa_supplicant[9852]: wlan0: CTRL-EVENT-CONNECTED - Connection to 50:91:e3:99:b4:9b completed [id=0 id_str=] May 02 11:13:39 volumio dhcpcd[9922]: wlan0: carrier acquired May 02 11:13:39 volumio wpa_supplicant[9852]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 02 11:13:39 volumio dhcpcd[9922]: wlan0: connected to Access Point `ANTONIN_5_EXT' May 02 11:13:39 volumio wpa_supplicant[9852]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE May 02 11:13:39 volumio dhcpcd[9922]: wlan0: IAID 01:a8:52:da May 02 11:13:39 volumio dhcpcd[9922]: wlan0: adding address fe80::e65f:1ff:fea8:52da May 02 11:13:39 volumio dhcpcd[9922]: ipv6_addaddr1: Permission denied May 02 11:13:39 volumio dhcpcd[9922]: wlan0: soliciting a DHCP lease May 02 11:13:39 volumio dhcpcd[9922]: wlan0: offered 192.168.1.64 from 192.168.1.20 May 02 11:13:39 volumio dhcpcd[9922]: wlan0: ignoring offer of 192.168.1.64 from 192.168.1.20 May 02 11:13:39 volumio dhcpcd[9922]: wlan0: probing address 192.168.1.64/24 May 02 11:13:40 volumio wireless.js[9740]: trying... May 02 11:13:40 volumio sudo[9937]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:40 volumio sudo[9937]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:40 volumio sudo[9937]: pam_unix(sudo:session): session closed for user root May 02 11:13:40 volumio dhcpcd[9922]: wlan0: soliciting an IPv6 router May 02 11:13:40 volumio ntpd[779]: 147.251.48.140 local addr 192.168.1.63 -> May 02 11:13:40 volumio volumio[922]: info: Volumio Network Manager: Network status updated: 1 May 02 11:13:41 volumio wireless.js[9740]: trying... May 02 11:13:41 volumio sudo[9954]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:41 volumio sudo[9954]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:41 volumio sudo[9954]: pam_unix(sudo:session): session closed for user root May 02 11:13:42 volumio wireless.js[9740]: trying... May 02 11:13:42 volumio sudo[9957]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:42 volumio sudo[9957]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:42 volumio sudo[9957]: pam_unix(sudo:session): session closed for user root May 02 11:13:42 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 11:13:42 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 11:13:42 volumio volumio[922]: info: Discovery: Getting this device information May 02 11:13:42 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:42 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:42 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 11:13:43 volumio wireless.js[9740]: trying... May 02 11:13:43 volumio sudo[9960]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:43 volumio sudo[9960]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:43 volumio sudo[9960]: pam_unix(sudo:session): session closed for user root May 02 11:13:44 volumio wireless.js[9740]: trying... May 02 11:13:44 volumio sudo[9963]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:44 volumio sudo[9963]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:44 volumio sudo[9963]: pam_unix(sudo:session): session closed for user root May 02 11:13:44 volumio dhcpcd[9922]: wlan0: leased 192.168.1.64 for 600 seconds May 02 11:13:44 volumio avahi-daemon[628]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.64. May 02 11:13:44 volumio avahi-daemon[628]: New relevant interface wlan0.IPv4 for mDNS. May 02 11:13:44 volumio dhcpcd[9922]: wlan0: adding route to 192.168.1.0/24 May 02 11:13:44 volumio dhcpcd[9922]: wlan0: adding default route via 192.168.1.20 May 02 11:13:44 volumio avahi-daemon[628]: Registering new address record for 192.168.1.64 on wlan0.IPv4. May 02 11:13:44 volumio dnsmasq[913]: reading /etc/resolv.conf May 02 11:13:44 volumio dnsmasq[913]: using nameserver 208.67.222.222#53 May 02 11:13:44 volumio dnsmasq[913]: using nameserver 208.67.220.220#53 May 02 11:13:44 volumio dnsmasq[913]: using nameserver 192.168.1.20#53 May 02 11:13:45 volumio wireless.js[9740]: trying... May 02 11:13:45 volumio sudo[9987]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 02 11:13:45 volumio sudo[9987]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:45 volumio sudo[9987]: pam_unix(sudo:session): session closed for user root May 02 11:13:45 volumio wireless.js[9740]: Connected to: ----ANTONIN_5_EXT May 02 11:13:45 volumio wireless.js[9740]: ---- May 02 11:13:45 volumio sudo[9990]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 11:13:45 volumio sudo[9990]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:45 volumio sudo[9990]: pam_unix(sudo:session): session closed for user root May 02 11:13:45 volumio wireless.js[9740]: ... joined AP, wlan0 IPv4 is 192.168.1.64, ipV6 is undefined May 02 11:13:45 volumio wireless.js[9740]: It's done! AP May 02 11:13:45 volumio systemd[1]: Started Wireless Services. May 02 11:13:45 volumio sudo[9451]: pam_unix(sudo:session): session closed for user root May 02 11:13:45 volumio sudo[9720]: pam_unix(sudo:session): session closed for user root May 02 11:13:45 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 02 11:13:45 volumio volumio[922]: info: Discovery: this is already registered, 2c0b382c-19eb-499d-9e5b-25e5ae31cd9e May 02 11:13:45 volumio volumio[922]: info: Discovery: Found device Volumio May 02 11:13:45 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:45 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:46 volumio ntpd[779]: Listen normally on 12 wlan0 192.168.1.64:123 May 02 11:13:46 volumio ntpd[779]: new interface(s) found: waking up resolver May 02 11:13:49 volumio sudo[10040]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 11:13:49 volumio sudo[10040]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:49 volumio sudo[10040]: pam_unix(sudo:session): session closed for user root May 02 11:13:49 volumio sudo[10043]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 11:13:49 volumio sudo[10043]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:49 volumio sudo[10043]: pam_unix(sudo:session): session closed for user root May 02 11:13:49 volumio sudo[10046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 02 11:13:49 volumio sudo[10046]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:49 volumio sudo[10046]: pam_unix(sudo:session): session closed for user root May 02 11:13:49 volumio volumio[922]: info: Upmpdcli Daemon Started May 02 11:13:50 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection May 02 11:13:50 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo May 02 11:13:50 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection May 02 11:13:50 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo May 02 11:13:50 volumio sudo[10049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 11:13:50 volumio sudo[10049]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:50 volumio sudo[10049]: pam_unix(sudo:session): session closed for user root May 02 11:13:50 volumio sudo[10052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 11:13:50 volumio sudo[10052]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:50 volumio sudo[10052]: pam_unix(sudo:session): session closed for user root May 02 11:13:50 volumio sudo[10055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 May 02 11:13:50 volumio sudo[10055]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:50 volumio sudo[10055]: pam_unix(sudo:session): session closed for user root May 02 11:13:50 volumio sudo[10060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 May 02 11:13:50 volumio sudo[10060]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:50 volumio sudo[10060]: pam_unix(sudo:session): session closed for user root May 02 11:13:50 volumio volumio[922]: info: Volumio Network Manager: Network status updated: 3 May 02 11:13:54 volumio volumio[922]: verbose: New Socket.io Connection to 192.168.1.62 from 192.168.1.73 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/134.0.0.0 Safari/537.36 CCleaner/134.0.0.0 Engine version: 3 Transport: polling Total Clients: 8 May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:54 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:54 volumio volumio[922]: info: Received Get System Info May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 11:13:54 volumio volumio[922]: info: Discovery: Getting this device information May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:54 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:54 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::volumioGetVisibleSources May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:54 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:54 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 02 11:13:54 volumio volumio[922]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 02 11:13:54 volumio volumio[922]: info: Received Get System Info May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 11:13:54 volumio volumio[922]: info: Discovery: Getting this device information May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:54 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:54 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:54 volumio volumio[922]: info: Listing playlists May 02 11:13:54 volumio volumio[922]: info: CoreCommandRouter::volumioGetQueue May 02 11:13:54 volumio volumio[922]: info: CoreStateMachine::getQueue May 02 11:13:54 volumio volumio[922]: info: CorePlayQueue::getQueue May 02 11:13:55 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart May 02 11:13:55 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart May 02 11:13:55 volumio volumio[922]: info: Refreshing Cached IP Addresses May 02 11:13:55 volumio sudo[10080]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli May 02 11:13:55 volumio sudo[10080]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:55 volumio sudo[10080]: pam_unix(sudo:session): session closed for user root May 02 11:13:55 volumio sudo[10083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 11:13:55 volumio sudo[10083]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:55 volumio sudo[10083]: pam_unix(sudo:session): session closed for user root May 02 11:13:55 volumio volumio[922]: error: Upnp client error: Error: This socket has been ended by the other party May 02 11:13:55 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart May 02 11:13:55 volumio sudo[10086]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 11:13:55 volumio sudo[10086]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:55 volumio sudo[10086]: pam_unix(sudo:session): session closed for user root May 02 11:13:55 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart May 02 11:13:55 volumio volumio[922]: info: Refreshing Cached IP Addresses May 02 11:13:55 volumio sudo[10089]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli May 02 11:13:55 volumio sudo[10089]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:55 volumio sudo[10089]: pam_unix(sudo:session): session closed for user root May 02 11:13:55 volumio sudo[10092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 11:13:55 volumio sudo[10092]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:55 volumio sudo[10092]: pam_unix(sudo:session): session closed for user root May 02 11:13:55 volumio volumio[922]: error: Upnp client error: Error: This socket has been ended by the other party May 02 11:13:55 volumio volumio[922]: verbose: New Socket.io Connection to 192.168.1.62 from 192.168.1.117 UA: Mozilla/5.0 (Linux; Android 10; Lenovo TB-8505F Build/QP1A.190711.020; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.100 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 May 02 11:13:55 volumio sudo[10095]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 11:13:55 volumio sudo[10095]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:13:55 volumio sudo[10095]: pam_unix(sudo:session): session closed for user root May 02 11:13:57 volumio volumio[922]: verbose: New Socket.io Connection to 192.168.1.62 from 192.168.1.117 UA: Mozilla/5.0 (Linux; Android 10; Lenovo TB-8505F Build/QP1A.190711.020; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.100 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 May 02 11:13:57 volumio volumio[922]: info: Received Get System Info May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 11:13:57 volumio volumio[922]: info: Discovery: Getting this device information May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:57 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:57 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::volumioGetVisibleSources May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:57 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 02 11:13:57 volumio volumio[922]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 02 11:13:57 volumio volumio[922]: info: Received Get System Info May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 11:13:57 volumio volumio[922]: info: Discovery: Getting this device information May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:57 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:13:57 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:13:57 volumio volumio[922]: info: Listing playlists May 02 11:13:57 volumio volumio[922]: info: CoreCommandRouter::volumioGetQueue May 02 11:13:57 volumio volumio[922]: info: CoreStateMachine::getQueue May 02 11:13:57 volumio volumio[922]: info: CorePlayQueue::getQueue May 02 11:14:05 volumio sudo[10113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 11:14:05 volumio sudo[10113]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:05 volumio sudo[10113]: pam_unix(sudo:session): session closed for user root May 02 11:14:05 volumio sudo[10116]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 11:14:05 volumio sudo[10116]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:05 volumio sudo[10116]: pam_unix(sudo:session): session closed for user root May 02 11:14:05 volumio sudo[10119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 02 11:14:05 volumio sudo[10119]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:05 volumio sudo[10119]: pam_unix(sudo:session): session closed for user root May 02 11:14:05 volumio sudo[10122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 11:14:05 volumio sudo[10122]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:05 volumio sudo[10122]: pam_unix(sudo:session): session closed for user root May 02 11:14:05 volumio volumio[922]: info: Upmpdcli Daemon Started May 02 11:14:05 volumio sudo[10125]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 11:14:05 volumio sudo[10125]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:05 volumio sudo[10125]: pam_unix(sudo:session): session closed for user root May 02 11:14:05 volumio sudo[10128]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 02 11:14:05 volumio sudo[10128]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:05 volumio sudo[10128]: pam_unix(sudo:session): session closed for user root May 02 11:14:05 volumio volumio[922]: info: Upmpdcli Daemon Started May 02 11:14:05 volumio volumio[922]: info: Executing endpoint metavolumio May 02 11:14:05 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 02 11:14:05 volumio volumio[922]: info: Executing endpoint metavolumio May 02 11:14:05 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 02 11:14:05 volumio volumio[922]: info: Executing endpoint metavolumio May 02 11:14:05 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 02 11:14:12 volumio volumio[922]: info: CoreCommandRouter::volumioPlay May 02 11:14:12 volumio volumio[922]: info: CoreStateMachine::play index undefined May 02 11:14:12 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:12 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:14:12 volumio volumio[922]: info: CoreStateMachine::startPlaybackTimer May 02 11:14:12 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:14:12 volumio volumio[922]: info: [1746177252256] ControllerTidal::clearAddPlayTrack May 02 11:14:12 volumio volumio[922]: info: Getting stream with soundQuality HI_RES May 02 11:14:12 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand stop May 02 11:14:12 volumio volumio[922]: info: sendMpdCommand stop took 0 milliseconds May 02 11:14:12 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clear May 02 11:14:12 volumio volumio[922]: info: May 02 11:14:12 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:12 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:12 volumio volumio[922]: info: sendMpdCommand clear took 0 milliseconds May 02 11:14:12 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/211491407&soundQuality=HI_RES" May 02 11:14:12 volumio volumio[922]: error: updateQueue error: null May 02 11:14:12 volumio volumio[922]: info: May 02 11:14:12 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:12 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:12 volumio volumio[922]: info: ------------------------------ 1ms May 02 11:14:12 volumio volumio[922]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/211491407&soundQuality=HI_RES" took 1 milliseconds May 02 11:14:12 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService mpd May 02 11:14:12 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand play May 02 11:14:12 volumio volumio[922]: info: ------------------------------ 1ms May 02 11:14:12 volumio volumio[922]: info: sendMpdCommand play took 1 milliseconds May 02 11:14:12 volumio volumio[922]: STREAMING PROXY: Handling url /?data=tidal://song/211491407&soundQuality=HI_RES May 02 11:14:12 volumio volumio[922]: info: Executing endpoint getStreamUrltidal May 02 11:14:12 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 02 11:14:12 volumio volumio[922]: info: getStreamUrl took 338 milliseconds May 02 11:14:12 volumio volumio[922]: error: Failed to retrieve real stream URL Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {"status":401,"subStatus":5003,"userMessage":"Requested quality is not allowed in user's subscription"} May 02 11:14:12 volumio volumio[922]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {\"status\":401,\"subStatus\":5003,\"userMessage\":\"Requested quality is not allowed in user's subscription\"}"} May 02 11:14:12 volumio volumio[922]: info: May 02 11:14:12 volumio volumio[922]: ---------------------------- MPD announces state update: player May 02 11:14:12 volumio volumio[922]: info: ControllerMpd::getState May 02 11:14:12 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand status May 02 11:14:12 volumio volumio[922]: error: MPD Playback Error: Failed to decode stream, moving to next track May 02 11:14:12 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clearerror May 02 11:14:12 volumio volumio[922]: info: sendMpdCommand status took 2 milliseconds May 02 11:14:12 volumio volumio[922]: verbose: ControllerMpd::parseState May 02 11:14:12 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 02 11:14:12 volumio volumio[922]: info: sendMpdCommand clearerror took 1 milliseconds May 02 11:14:12 volumio volumio[922]: info: sendMpdCommand playlistinfo took 0 milliseconds May 02 11:14:12 volumio volumio[922]: verbose: ControllerMpd::parseTrackInfo May 02 11:14:12 volumio volumio[922]: info: ControllerMpd::pushState May 02 11:14:12 volumio volumio[922]: info: CoreCommandRouter::servicePushState May 02 11:14:12 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:12 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 11:14:12 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:12 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:12 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:12 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:14:12 volumio volumio[922]: 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":"211491407&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/211491407&soundQuality=HI_RES","trackType":"tidal"} May 02 11:14:12 volumio volumio[922]: verbose: CURRENT POSITION 0 May 02 11:14:12 volumio volumio[922]: info: CoreStateMachine::syncState stateService stop May 02 11:14:12 volumio volumio[922]: info: CoreStateMachine::syncState currentStatus stop May 02 11:14:12 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:12 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:12 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:12 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:12 volumio volumio[922]: info: No code May 02 11:14:12 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:12 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:12 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:12 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:12 volumio volumio[922]: info: ------------------------------ 14ms May 02 11:14:12 volumio volumio[922]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.d9f0fblH5vaOcDRqP0kdnQ07S2u1.de8801d3472549eb3e1989fc8b974952.state.status' May 02 11:14:12 volumio volumio[922]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.d9f0fblH5vaOcDRqP0kdnQ07S2u1.de8801d3472549eb3e1989fc8b974952.state.status' May 02 11:14:13 volumio volumio[922]: info: Moving to next track after playback error May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::volumioPlay May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::play index 1 May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::stop May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::play index undefined May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:13 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::startPlaybackTimer May 02 11:14:13 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::volumioGetVisibleSources May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 02 11:14:13 volumio volumio[922]: info: [1746177253610] ControllerTidal::clearAddPlayTrack May 02 11:14:13 volumio volumio[922]: info: Getting stream with soundQuality HI_RES May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand stop May 02 11:14:13 volumio volumio[922]: info: sendMpdCommand stop took 1 milliseconds May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clear May 02 11:14:13 volumio volumio[922]: info: May 02 11:14:13 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:13 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:13 volumio volumio[922]: info: sendMpdCommand clear took 1 milliseconds May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES" May 02 11:14:13 volumio volumio[922]: error: updateQueue error: null May 02 11:14:13 volumio volumio[922]: info: May 02 11:14:13 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:13 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:13 volumio volumio[922]: info: ------------------------------ 2ms May 02 11:14:13 volumio volumio[922]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES" took 1 milliseconds May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService mpd May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand play May 02 11:14:13 volumio volumio[922]: info: ------------------------------ 1ms May 02 11:14:13 volumio volumio[922]: info: sendMpdCommand play took 1 milliseconds May 02 11:14:13 volumio volumio[922]: STREAMING PROXY: Handling url /?data=tidal://song/298421450&soundQuality=HI_RES May 02 11:14:13 volumio volumio[922]: info: Executing endpoint getStreamUrltidal May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 11:14:13 volumio volumio[922]: info: Discovery: Getting this device information May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::volumioPlay May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::play index undefined May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:13 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::startPlaybackTimer May 02 11:14:13 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::volumioGetVisibleSources May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 02 11:14:13 volumio volumio[922]: info: [1746177253706] ControllerTidal::clearAddPlayTrack May 02 11:14:13 volumio volumio[922]: info: Getting stream with soundQuality HI_RES May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand stop May 02 11:14:13 volumio volumio[922]: info: May 02 11:14:13 volumio volumio[922]: ---------------------------- MPD announces state update: player May 02 11:14:13 volumio volumio[922]: info: sendMpdCommand stop took 2 milliseconds May 02 11:14:13 volumio volumio[922]: info: ControllerMpd::getState May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand status May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clear May 02 11:14:13 volumio volumio[922]: info: May 02 11:14:13 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:13 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:13 volumio volumio[922]: info: sendMpdCommand status took 1 milliseconds May 02 11:14:13 volumio volumio[922]: info: sendMpdCommand clear took 1 milliseconds May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::parseState May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES" May 02 11:14:13 volumio volumio[922]: error: updateQueue error: null May 02 11:14:13 volumio volumio[922]: info: May 02 11:14:13 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:13 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:13 volumio volumio[922]: info: ------------------------------ 2ms May 02 11:14:13 volumio volumio[922]: info: sendMpdCommand playlistinfo took 1 milliseconds May 02 11:14:13 volumio volumio[922]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES" took 1 milliseconds May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::parseTrackInfo May 02 11:14:13 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService mpd May 02 11:14:13 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand play May 02 11:14:13 volumio volumio[922]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 02 11:14:13 volumio volumio[922]: info: ------------------------------ 4ms May 02 11:14:13 volumio volumio[922]: info: ------------------------------ 2ms May 02 11:14:13 volumio volumio[922]: info: sendMpdCommand play took 1 milliseconds May 02 11:14:13 volumio volumio[922]: STREAMING PROXY: Handling url /?data=tidal://song/298421450&soundQuality=HI_RES May 02 11:14:13 volumio volumio[922]: info: Executing endpoint getStreamUrltidal May 02 11:14:13 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 02 11:14:13 volumio volumio[922]: info: getStreamUrl took 330 milliseconds May 02 11:14:13 volumio volumio[922]: error: Failed to retrieve real stream URL Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {"status":401,"subStatus":5003,"userMessage":"Requested quality is not allowed in user's subscription"} May 02 11:14:13 volumio volumio[922]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {\"status\":401,\"subStatus\":5003,\"userMessage\":\"Requested quality is not allowed in user's subscription\"}"} May 02 11:14:14 volumio volumio[922]: info: getStreamUrl took 440 milliseconds May 02 11:14:14 volumio volumio[922]: error: Failed to retrieve real stream URL Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {"status":401,"subStatus":5003,"userMessage":"Requested quality is not allowed in user's subscription"} May 02 11:14:14 volumio volumio[922]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {\"status\":401,\"subStatus\":5003,\"userMessage\":\"Requested quality is not allowed in user's subscription\"}"} May 02 11:14:14 volumio volumio[922]: info: May 02 11:14:14 volumio volumio[922]: ---------------------------- MPD announces state update: player May 02 11:14:14 volumio volumio[922]: info: ControllerMpd::getState May 02 11:14:14 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand status May 02 11:14:14 volumio volumio[922]: error: MPD Playback Error: Failed to decode stream, moving to next track May 02 11:14:14 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clearerror May 02 11:14:14 volumio volumio[922]: info: sendMpdCommand status took 2 milliseconds May 02 11:14:14 volumio volumio[922]: verbose: ControllerMpd::parseState May 02 11:14:14 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 02 11:14:14 volumio volumio[922]: info: sendMpdCommand clearerror took 1 milliseconds May 02 11:14:14 volumio volumio[922]: info: sendMpdCommand playlistinfo took 1 milliseconds May 02 11:14:14 volumio volumio[922]: verbose: ControllerMpd::parseTrackInfo May 02 11:14:14 volumio volumio[922]: info: ControllerMpd::pushState May 02 11:14:14 volumio volumio[922]: info: CoreCommandRouter::servicePushState May 02 11:14:14 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:14 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 11:14:14 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:14 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:14 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:14 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:14 volumio volumio[922]: 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":"298421450&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES","trackType":"tidal"} May 02 11:14:14 volumio volumio[922]: verbose: CURRENT POSITION 1 May 02 11:14:14 volumio volumio[922]: info: CoreStateMachine::syncState stateService stop May 02 11:14:14 volumio volumio[922]: info: CoreStateMachine::syncState currentStatus stop May 02 11:14:14 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:14 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:14 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:14 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:14 volumio volumio[922]: info: No code May 02 11:14:14 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:14 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:14 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:14 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:14 volumio volumio[922]: info: ------------------------------ 14ms May 02 11:14:14 volumio volumio[922]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.d9f0fblH5vaOcDRqP0kdnQ07S2u1.de8801d3472549eb3e1989fc8b974952.state.status' May 02 11:14:14 volumio volumio[922]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.d9f0fblH5vaOcDRqP0kdnQ07S2u1.de8801d3472549eb3e1989fc8b974952.state.status' May 02 11:14:15 volumio volumio[922]: info: Moving to next track after playback error May 02 11:14:15 volumio volumio[922]: info: CoreCommandRouter::volumioPlay May 02 11:14:15 volumio volumio[922]: info: CoreStateMachine::play index 2 May 02 11:14:15 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:15 volumio volumio[922]: info: CoreStateMachine::stop May 02 11:14:15 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:15 volumio volumio[922]: info: CoreStateMachine::play index undefined May 02 11:14:15 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:15 volumio volumio[922]: info: CorePlayQueue::getTrack 2 May 02 11:14:16 volumio volumio[922]: info: CoreCommandRouter::volumioPlay May 02 11:14:16 volumio volumio[922]: info: CoreStateMachine::play index undefined May 02 11:14:16 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:16 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:14:16 volumio volumio[922]: info: CoreStateMachine::startPlaybackTimer May 02 11:14:16 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:14:16 volumio volumio[922]: info: [1746177256025] ControllerTidal::clearAddPlayTrack May 02 11:14:16 volumio volumio[922]: info: Getting stream with soundQuality HI_RES May 02 11:14:16 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand stop May 02 11:14:16 volumio volumio[922]: info: sendMpdCommand stop took 1 milliseconds May 02 11:14:16 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clear May 02 11:14:16 volumio volumio[922]: info: May 02 11:14:16 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:16 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:16 volumio volumio[922]: info: sendMpdCommand clear took 1 milliseconds May 02 11:14:16 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/211491407&soundQuality=HI_RES" May 02 11:14:16 volumio volumio[922]: error: updateQueue error: null May 02 11:14:16 volumio volumio[922]: info: May 02 11:14:16 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:16 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:16 volumio volumio[922]: info: ------------------------------ 4ms May 02 11:14:16 volumio volumio[922]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/211491407&soundQuality=HI_RES" took 3 milliseconds May 02 11:14:16 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService mpd May 02 11:14:16 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand play May 02 11:14:16 volumio volumio[922]: info: ------------------------------ 1ms May 02 11:14:16 volumio volumio[922]: info: sendMpdCommand play took 1 milliseconds May 02 11:14:16 volumio volumio[922]: STREAMING PROXY: Handling url /?data=tidal://song/211491407&soundQuality=HI_RES May 02 11:14:16 volumio volumio[922]: info: Executing endpoint getStreamUrltidal May 02 11:14:16 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 02 11:14:16 volumio volumio[922]: info: getStreamUrl took 275 milliseconds May 02 11:14:16 volumio volumio[922]: error: Failed to retrieve real stream URL Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {"status":401,"subStatus":5003,"userMessage":"Requested quality is not allowed in user's subscription"} May 02 11:14:16 volumio volumio[922]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {\"status\":401,\"subStatus\":5003,\"userMessage\":\"Requested quality is not allowed in user's subscription\"}"} May 02 11:14:16 volumio volumio[922]: info: May 02 11:14:16 volumio volumio[922]: ---------------------------- MPD announces state update: player May 02 11:14:16 volumio volumio[922]: info: ControllerMpd::getState May 02 11:14:16 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand status May 02 11:14:16 volumio volumio[922]: error: MPD Playback Error: Failed to decode stream, moving to next track May 02 11:14:16 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clearerror May 02 11:14:16 volumio volumio[922]: info: sendMpdCommand status took 2 milliseconds May 02 11:14:16 volumio volumio[922]: verbose: ControllerMpd::parseState May 02 11:14:16 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 02 11:14:16 volumio volumio[922]: info: sendMpdCommand clearerror took 1 milliseconds May 02 11:14:16 volumio volumio[922]: info: sendMpdCommand playlistinfo took 1 milliseconds May 02 11:14:16 volumio volumio[922]: verbose: ControllerMpd::parseTrackInfo May 02 11:14:16 volumio volumio[922]: info: ControllerMpd::pushState May 02 11:14:16 volumio volumio[922]: info: CoreCommandRouter::servicePushState May 02 11:14:16 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:16 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 11:14:16 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:16 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:16 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:16 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:14:16 volumio volumio[922]: 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":"211491407&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/211491407&soundQuality=HI_RES","trackType":"tidal"} May 02 11:14:16 volumio volumio[922]: verbose: CURRENT POSITION 0 May 02 11:14:16 volumio volumio[922]: info: CoreStateMachine::syncState stateService stop May 02 11:14:16 volumio volumio[922]: info: CoreStateMachine::syncState currentStatus stop May 02 11:14:16 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:16 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:16 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:16 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:16 volumio volumio[922]: info: No code May 02 11:14:16 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:16 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:16 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:16 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:16 volumio volumio[922]: info: ------------------------------ 14ms May 02 11:14:16 volumio volumio[922]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.d9f0fblH5vaOcDRqP0kdnQ07S2u1.de8801d3472549eb3e1989fc8b974952.state.status' May 02 11:14:16 volumio volumio[922]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.d9f0fblH5vaOcDRqP0kdnQ07S2u1.de8801d3472549eb3e1989fc8b974952.state.status' May 02 11:14:17 volumio volumio[922]: info: Moving to next track after playback error May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::volumioPlay May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::play index 1 May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::stop May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::play index undefined May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:17 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::startPlaybackTimer May 02 11:14:17 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::volumioGetVisibleSources May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 02 11:14:17 volumio volumio[922]: info: [1746177257323] ControllerTidal::clearAddPlayTrack May 02 11:14:17 volumio volumio[922]: info: Getting stream with soundQuality HI_RES May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand stop May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand stop took 1 milliseconds May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clear May 02 11:14:17 volumio volumio[922]: info: May 02 11:14:17 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:17 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand clear took 0 milliseconds May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES" May 02 11:14:17 volumio volumio[922]: error: updateQueue error: null May 02 11:14:17 volumio volumio[922]: info: May 02 11:14:17 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:17 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:17 volumio volumio[922]: info: ------------------------------ 1ms May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES" took 0 milliseconds May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService mpd May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand play May 02 11:14:17 volumio volumio[922]: info: ------------------------------ 1ms May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand play took 1 milliseconds May 02 11:14:17 volumio volumio[922]: STREAMING PROXY: Handling url /?data=tidal://song/298421450&soundQuality=HI_RES May 02 11:14:17 volumio volumio[922]: info: Executing endpoint getStreamUrltidal May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::volumioPlay May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::play index undefined May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::volumioPlay May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::play index undefined May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:17 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::startPlaybackTimer May 02 11:14:17 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::volumioGetVisibleSources May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 02 11:14:17 volumio volumio[922]: info: [1746177257459] ControllerTidal::clearAddPlayTrack May 02 11:14:17 volumio volumio[922]: info: Getting stream with soundQuality HI_RES May 02 11:14:17 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::startPlaybackTimer May 02 11:14:17 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::volumioGetVisibleSources May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 02 11:14:17 volumio volumio[922]: info: [1746177257460] ControllerTidal::clearAddPlayTrack May 02 11:14:17 volumio volumio[922]: info: Getting stream with soundQuality HI_RES May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand stop May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand stop May 02 11:14:17 volumio volumio[922]: info: May 02 11:14:17 volumio volumio[922]: ---------------------------- MPD announces state update: player May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand stop took 1 milliseconds May 02 11:14:17 volumio volumio[922]: info: ControllerMpd::getState May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand status May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clear May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand stop took 2 milliseconds May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clear May 02 11:14:17 volumio volumio[922]: info: May 02 11:14:17 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:17 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand status took 2 milliseconds May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand clear took 2 milliseconds May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::parseState May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES" May 02 11:14:17 volumio volumio[922]: info: May 02 11:14:17 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:17 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:17 volumio volumio[922]: error: updateQueue error: null May 02 11:14:17 volumio volumio[922]: info: May 02 11:14:17 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:17 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand clear took 2 milliseconds May 02 11:14:17 volumio volumio[922]: info: ------------------------------ 3ms May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand playlistinfo took 2 milliseconds May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES" took 2 milliseconds May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES" May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::parseTrackInfo May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService mpd May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand play May 02 11:14:17 volumio volumio[922]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 02 11:14:17 volumio volumio[922]: info: ------------------------------ 5ms May 02 11:14:17 volumio volumio[922]: STREAMING PROXY: Handling url /?data=tidal://song/298421450&soundQuality=HI_RES May 02 11:14:17 volumio volumio[922]: info: May 02 11:14:17 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:17 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:17 volumio volumio[922]: info: ------------------------------ 15ms May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES" took 14 milliseconds May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand play took 14 milliseconds May 02 11:14:17 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService mpd May 02 11:14:17 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand play May 02 11:14:17 volumio volumio[922]: info: ------------------------------ 1ms May 02 11:14:17 volumio volumio[922]: info: sendMpdCommand play took 1 milliseconds May 02 11:14:17 volumio volumio[922]: info: Executing endpoint getStreamUrltidal May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 02 11:14:17 volumio volumio[922]: info: getStreamUrl took 313 milliseconds May 02 11:14:17 volumio volumio[922]: error: Failed to retrieve real stream URL Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {"status":401,"subStatus":5003,"userMessage":"Requested quality is not allowed in user's subscription"} May 02 11:14:17 volumio volumio[922]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {\"status\":401,\"subStatus\":5003,\"userMessage\":\"Requested quality is not allowed in user's subscription\"}"} May 02 11:14:17 volumio volumio[922]: info: getStreamUrl took 301 milliseconds May 02 11:14:17 volumio volumio[922]: error: Failed to retrieve real stream URL Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {"status":401,"subStatus":5003,"userMessage":"Requested quality is not allowed in user's subscription"} May 02 11:14:17 volumio volumio[922]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {\"status\":401,\"subStatus\":5003,\"userMessage\":\"Requested quality is not allowed in user's subscription\"}"} May 02 11:14:17 volumio volumio[922]: info: May 02 11:14:17 volumio volumio[922]: ---------------------------- MPD announces system playlist update May 02 11:14:17 volumio volumio[922]: info: Ignoring MPD Status Update May 02 11:14:17 volumio volumio[922]: STREAMING PROXY: Handling url /?data=tidal://song/298421450&soundQuality=HI_RES May 02 11:14:17 volumio volumio[922]: info: ------------------------------ 1ms May 02 11:14:17 volumio volumio[922]: info: Executing endpoint getStreamUrltidal May 02 11:14:17 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 02 11:14:18 volumio volumio[922]: info: getStreamUrl took 457 milliseconds May 02 11:14:18 volumio volumio[922]: error: Failed to retrieve real stream URL Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {"status":401,"subStatus":5003,"userMessage":"Requested quality is not allowed in user's subscription"} May 02 11:14:18 volumio volumio[922]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get TIDAL Stream URL: failed to get stream from provider tidal: rpc error: code = PermissionDenied desc = failed to get track playback info: got 401: {\"status\":401,\"subStatus\":5003,\"userMessage\":\"Requested quality is not allowed in user's subscription\"}"} May 02 11:14:18 volumio volumio[922]: info: May 02 11:14:18 volumio volumio[922]: ---------------------------- MPD announces state update: player May 02 11:14:18 volumio volumio[922]: info: ControllerMpd::getState May 02 11:14:18 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand status May 02 11:14:18 volumio volumio[922]: error: MPD Playback Error: Failed to decode stream, moving to next track May 02 11:14:18 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand clearerror May 02 11:14:18 volumio volumio[922]: info: sendMpdCommand status took 2 milliseconds May 02 11:14:18 volumio volumio[922]: verbose: ControllerMpd::parseState May 02 11:14:18 volumio volumio[922]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 02 11:14:18 volumio volumio[922]: info: sendMpdCommand clearerror took 1 milliseconds May 02 11:14:18 volumio volumio[922]: info: sendMpdCommand playlistinfo took 0 milliseconds May 02 11:14:18 volumio volumio[922]: verbose: ControllerMpd::parseTrackInfo May 02 11:14:18 volumio volumio[922]: info: ControllerMpd::pushState May 02 11:14:18 volumio volumio[922]: info: CoreCommandRouter::servicePushState May 02 11:14:18 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:18 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 11:14:18 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:18 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:18 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:18 volumio volumio[922]: info: CorePlayQueue::getTrack 1 May 02 11:14:18 volumio volumio[922]: 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":"298421450&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/298421450&soundQuality=HI_RES","trackType":"tidal"} May 02 11:14:18 volumio volumio[922]: verbose: CURRENT POSITION 1 May 02 11:14:18 volumio volumio[922]: info: CoreStateMachine::syncState stateService stop May 02 11:14:18 volumio volumio[922]: info: CoreStateMachine::syncState currentStatus stop May 02 11:14:18 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:18 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:18 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:18 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:18 volumio volumio[922]: info: No code May 02 11:14:18 volumio volumio[922]: info: CoreStateMachine::pushState May 02 11:14:18 volumio volumio[922]: info: CoreCommandRouter::volumioPushState May 02 11:14:18 volumio volumio[922]: info: MRS: Pushing multiroomSync output update for this device May 02 11:14:18 volumio volumio[922]: info: MRS: Pushing multiroomSync output May 02 11:14:18 volumio volumio[922]: info: ------------------------------ 13ms May 02 11:14:18 volumio volumio[922]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.d9f0fblH5vaOcDRqP0kdnQ07S2u1.de8801d3472549eb3e1989fc8b974952.state.status' May 02 11:14:18 volumio volumio[922]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.d9f0fblH5vaOcDRqP0kdnQ07S2u1.de8801d3472549eb3e1989fc8b974952.state.status' May 02 11:14:19 volumio volumio[922]: info: Moving to next track after playback error May 02 11:14:19 volumio volumio[922]: info: CoreCommandRouter::volumioPlay May 02 11:14:19 volumio volumio[922]: info: CoreStateMachine::play index 2 May 02 11:14:19 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:19 volumio volumio[922]: info: CoreStateMachine::stop May 02 11:14:19 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:19 volumio volumio[922]: info: CoreStateMachine::play index undefined May 02 11:14:19 volumio volumio[922]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 11:14:19 volumio volumio[922]: info: CorePlayQueue::getTrack 2 May 02 11:14:22 volumio ntpd[779]: Soliciting pool server 2606:4700:f1::123 May 02 11:14:22 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 02 11:14:22 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 02 11:14:22 volumio ntpd[779]: Soliciting pool server 147.251.48.140 May 02 11:14:23 volumio ntpd[779]: Soliciting pool server 94.124.107.190 May 02 11:14:28 volumio volumio[922]: info: Enabling plugin fusiondsp May 02 11:14:28 volumio volumio[922]: info: Loading plugin "fusiondsp"... May 02 11:14:28 volumio volumio[922]: info: Preparing to generate the ALSA configuration file May 02 11:14:28 volumio volumio[922]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 02 11:14:28 volumio volumio[922]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 02 11:14:28 volumio volumio[922]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 02 11:14:28 volumio volumio[922]: info: Reading ALSA contributions from plugins. May 02 11:14:28 volumio volumio[922]: info: Asound.conf file written May 02 11:14:28 volumio sudo[10163]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 02 11:14:28 volumio sudo[10163]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:28 volumio sudo[10163]: pam_unix(sudo:session): session closed for user root May 02 11:14:28 volumio volumio[922]: xcb_connection_has_error() returned true May 02 11:14:28 volumio volumio[922]: Found hardware: "RPi-WM8804" "" "" "" "" May 02 11:14:28 volumio volumio[922]: Hardware is initialized using a generic method May 02 11:14:28 volumio volumio[922]: info: Output device has changed, restarting MPD May 02 11:14:28 volumio sudo[10168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 11:14:28 volumio sudo[10168]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:28 volumio sudo[10168]: pam_unix(sudo:session): session closed for user root May 02 11:14:28 volumio volumio[922]: info: Output device has changed, restarting Shairport Sync May 02 11:14:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 11:14:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 11:14:28 volumio sudo[10171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 11:14:28 volumio sudo[10171]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:28 volumio systemd[1]: Stopping Music Player Daemon... May 02 11:14:28 volumio systemd[1]: mpd.service: Succeeded. May 02 11:14:28 volumio volumio[922]: xcb_connection_has_error() returned true May 02 11:14:28 volumio volumio[922]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 11:14:28 volumio volumio[922]: xcb_connection_has_error() returned true May 02 11:14:28 volumio systemd[1]: Stopped Music Player Daemon. May 02 11:14:28 volumio volumio[922]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 02 11:14:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 11:14:28 volumio vtcs[5406]: [2025-05-02 11:14:28.734] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE May 02 11:14:28 volumio vtcs[5406]: [2025-05-02 11:14:28.735] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected May 02 11:14:28 volumio systemd[1]: Starting Music Player Daemon... May 02 11:14:28 volumio volumio[922]: info: PLUGIN START: fusiondsp May 02 11:14:28 volumio volumio[922]: info: Loading i18n strings for locale cs May 02 11:14:28 volumio volumio[922]: info: Plugin fusiondsp has duplicated i18n key SAVE. It is ignored. May 02 11:14:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 02 11:14:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 11:14:28 volumio volumio[922]: info: FusionDsp - mixtype--------------------- Software May 02 11:14:28 volumio volumio[922]: info: Preparing to generate the ALSA configuration file May 02 11:14:28 volumio sudo[10181]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 02 11:14:28 volumio sudo[10181]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:28 volumio volumio[922]: info: Done. May 02 11:14:28 volumio sudo[10176]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 02 11:14:28 volumio sudo[10176]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:28 volumio systemd[1]: Stopping Volumio Tidal Connect Service... May 02 11:14:28 volumio systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 02 11:14:28 volumio sudo[10176]: pam_unix(sudo:session): session closed for user root May 02 11:14:28 volumio systemd[1]: vtcs.service: Succeeded. May 02 11:14:28 volumio systemd[1]: Stopped Volumio Tidal Connect Service. May 02 11:14:28 volumio volumio[922]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 02 11:14:28 volumio volumio[922]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 02 11:14:28 volumio volumio[922]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 02 11:14:28 volumio volumio[922]: info: Reading ALSA contributions from plugins. May 02 11:14:28 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:14:28 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 02 11:14:28 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:14:28 volumio sudo[10188]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 02 11:14:28 volumio sudo[10188]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:28 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:14:28 volumio volumio[922]: info: MPD Permissions set May 02 11:14:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 11:14:28 volumio sudo[10181]: pam_unix(sudo:session): session closed for user root May 02 11:14:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 11:14:28 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 11:14:28 volumio sudo[10188]: pam_unix(sudo:session): session closed for user root May 02 11:14:28 volumio volumio[922]: info: Starting Shairport Sync May 02 11:14:28 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:14:28 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:14:28 volumio volumio[922]: info: CoreCommandRouter::volumioPause May 02 11:14:28 volumio volumio[922]: info: CoreStateMachine::pause May 02 11:14:28 volumio volumio[922]: info: mpdhttpout --- Volumio set on pause May 02 11:14:28 volumio volumio[922]: info: mpdhttpout ---Configuration successfully added to mpd.conf. May 02 11:14:28 volumio volumio[922]: info: Asound.conf file unchanged, so no further update is needed May 02 11:14:28 volumio volumio[922]: info: Output device has changed, restarting MPD May 02 11:14:28 volumio sudo[10197]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 11:14:28 volumio sudo[10197]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:28 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 11:14:28 volumio systemd[1]: shairport-sync.service: Succeeded. May 02 11:14:28 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 11:14:28 volumio sudo[10200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 11:14:28 volumio sudo[10200]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:28 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 11:14:29 volumio sudo[10197]: pam_unix(sudo:session): session closed for user root May 02 11:14:29 volumio sudo[10200]: pam_unix(sudo:session): session closed for user root May 02 11:14:29 volumio volumio[922]: info: Output device has changed, restarting Shairport Sync May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 11:14:29 volumio sudo[10204]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 11:14:29 volumio sudo[10204]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:29 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 02 11:14:29 volumio systemd[1]: mpd.service: Succeeded. May 02 11:14:29 volumio systemd[1]: Stopped Music Player Daemon. May 02 11:14:29 volumio systemd[1]: Starting Music Player Daemon... May 02 11:14:29 volumio volumio[922]: xcb_connection_has_error() returned true May 02 11:14:29 volumio volumio[922]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 11:14:29 volumio volumio[922]: xcb_connection_has_error() returned true May 02 11:14:29 volumio volumio[922]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 11:14:29 volumio sudo[10215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 02 11:14:29 volumio sudo[10215]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:29 volumio sudo[10211]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 02 11:14:29 volumio sudo[10211]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:29 volumio sudo[10211]: pam_unix(sudo:session): session closed for user root May 02 11:14:29 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:14:29 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 02 11:14:29 volumio sudo[10219]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 02 11:14:29 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 02 11:14:29 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:14:29 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 02 11:14:29 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::getUIConfigOnPlugin May 02 11:14:29 volumio volumio[922]: info: MPD Permissions set May 02 11:14:29 volumio volumio[922]: info: Shairport-Sync Started May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 11:14:29 volumio volumio[922]: info: FusionDsp - May 02 11:14:29 volumio sudo[10219]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:29 volumio sudo[10215]: pam_unix(sudo:session): session closed for user root May 02 11:14:29 volumio sudo[10219]: pam_unix(sudo:session): session closed for user root May 02 11:14:29 volumio volumio[922]: info: FusionDsp - undefined May 02 11:14:29 volumio volumio[922]: info: Starting Shairport Sync May 02 11:14:29 volumio volumio[922]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::volumioGetState May 02 11:14:29 volumio volumio[922]: info: CorePlayQueue::getTrack 0 May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::volumioPause May 02 11:14:29 volumio volumio[922]: info: CoreStateMachine::pause May 02 11:14:29 volumio volumio[922]: info: mpdhttpout --- Volumio set on pause May 02 11:14:29 volumio sudo[10229]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 11:14:29 volumio sudo[10229]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:29 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 11:14:29 volumio systemd[1]: shairport-sync.service: Succeeded. May 02 11:14:29 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 11:14:29 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 11:14:29 volumio volumio[922]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 02 11:14:29 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 11:14:29 volumio sudo[10229]: pam_unix(sudo:session): session closed for user root May 02 11:14:29 volumio volumio[922]: info: Shairport-Sync Started May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::getUIConfigOnPlugin May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::getUIConfigOnPlugin May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::getUIConfigOnPlugin May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::getUIConfigOnPlugin May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::getUIConfigOnPlugin May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::getUIConfigOnPlugin May 02 11:14:29 volumio volumio[922]: info: CoreCommandRouter::getUIConfigOnPlugin May 02 11:14:29 volumio volumio[922]: info: FusionDsp - May 02 11:14:29 volumio volumio[922]: info: FusionDsp - May 02 11:14:29 volumio volumio[922]: info: FusionDsp - May 02 11:14:29 volumio mpd[10220]: May 02 11:14 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 02 11:14:29 volumio systemd[1]: Started Music Player Daemon. May 02 11:14:30 volumio sudo[10171]: pam_unix(sudo:session): session closed for user root May 02 11:14:30 volumio sudo[10204]: pam_unix(sudo:session): session closed for user root May 02 11:14:30 volumio volumio[922]: info: FusionDsp - May 02 11:14:30 volumio volumio[922]: info: FusionDsp - May 02 11:14:30 volumio volumio[922]: info: FusionDsp - May 02 11:14:30 volumio volumio[922]: info: FusionDsp - May 02 11:14:30 volumio volumio[922]: info: FusionDsp - undefined May 02 11:14:30 volumio volumio[922]: info: FusionDsp - undefined May 02 11:14:30 volumio volumio[922]: info: FusionDsp - undefined May 02 11:14:30 volumio volumio[922]: info: FusionDsp - undefined May 02 11:14:30 volumio volumio[922]: info: FusionDsp - undefined May 02 11:14:30 volumio volumio[922]: info: FusionDsp - undefined May 02 11:14:30 volumio volumio[922]: info: FusionDsp - undefined May 02 11:14:30 volumio volumio[922]: error: MPD error: The expression evaluated to a falsy value: May 02 11:14:30 volumio volumio[922]: assert.ok(self.idling) May 02 11:14:30 volumio volumio[922]: error: The expression evaluated to a falsy value: May 02 11:14:30 volumio volumio[922]: assert.ok(self.idling) May 02 11:14:30 volumio volumio[922]: error: updateQueue error: null May 02 11:14:30 volumio volumio[922]: info: camilladsp service started and running in background, instance 1 May 02 11:14:30 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 11:14:30 volumio volumio[922]: xcb_connection_has_error() returned true May 02 11:14:30 volumio volumio[922]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA May 02 11:14:30 volumio volumio[922]: info: FusionDsp loaded May 02 11:14:30 volumio volumio[922]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 11:14:30 volumio sudo[10261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 02 11:14:30 volumio sudo[10261]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 11:14:30 volumio volumio[922]: info: FusionDsp - Reporting Fusion DSP Enabled May 02 11:14:30 volumio volumio[922]: info: Adding Signal Path Element [object Object] May 02 11:14:30 volumio volumio[922]: info: Adding fusiondspeq DSP Signal Path Element May 02 11:14:30 volumio volumio[922]: info: FusionDsp - ---- installed callbackRead May 02 11:14:30 volumio volumio[922]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 02 11:14:30 volumio volumio[922]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT May 02 11:14:30 volumio volumio[922]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) May 02 11:14:30 volumio volumio[922]: at onErrorNT (internal/child_process.js:465:16) May 02 11:14:30 volumio volumio[922]: at processTicksAndRejections (internal/process/task_queues.js:80:21) { May 02 11:14:30 volumio volumio[922]: errno: -2, May 02 11:14:30 volumio volumio[922]: code: 'ENOENT', May 02 11:14:30 volumio volumio[922]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', May 02 11:14:30 volumio volumio[922]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', May 02 11:14:30 volumio volumio[922]: spawnargs: [ May 02 11:14:30 volumio volumio[922]: '-p', May 02 11:14:30 volumio volumio[922]: 9876, May 02 11:14:30 volumio volumio[922]: '-o', May 02 11:14:30 volumio volumio[922]: '/tmp/camilladsp.log', May 02 11:14:30 volumio volumio[922]: '-l', May 02 11:14:30 volumio volumio[922]: 'warn', May 02 11:14:30 volumio volumio[922]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' May 02 11:14:30 volumio volumio[922]: ] May 02 11:14:30 volumio volumio[922]: } May 02 11:14:30 volumio volumio[922]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 02 11:14:30 volumio systemd[1]: Started FusionDsp Daemon. May 02 11:14:31 volumio sudo[10261]: pam_unix(sudo:session): session closed for user root May 02 11:14:31 volumio volumio[10263]: /usr/bin/python3: can't open file '/data/plugins/audio_interface/fusiondsp/cgui/main.py': [Errno 2] No such file or directory May 02 11:14:31 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=2/INVALIDARGUMENT May 02 11:14:31 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 02 11:14:31 volumio sudo[10274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-02 11:13 May 02 11:14:31 volumio sudo[10274]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"