-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2025-10-26 12:02:32 CET. -- Oct 26 12:01:08 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:10 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:11 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:11+01:00" level=error msg="did not receive last pong from dealer, 300s passed" Oct 26 12:01:11 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:11+01:00" level=error msg="did not receive last pong ack from accesspoint, 360s passed" Oct 26 12:01:11 volumiolenn wpa_supplicant[870]: wlan0: CTRL-EVENT-DISCONNECTED bssid=f0:b0:14:e8:30:6a reason=2 Oct 26 12:01:11 volumiolenn dhcpcd[882]: wlan0: carrier lost Oct 26 12:01:11 volumiolenn wpa_supplicant[870]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Oct 26 12:01:11 volumiolenn wpa_supplicant[870]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=LU Oct 26 12:01:12 volumiolenn avahi-daemon[589]: Withdrawing address record for 192.168.1.151 on wlan0. Oct 26 12:01:12 volumiolenn avahi-daemon[589]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.151. Oct 26 12:01:12 volumiolenn avahi-daemon[589]: Interface wlan0.IPv4 no longer relevant for mDNS. Oct 26 12:01:12 volumiolenn dhcpcd[882]: wlan0: deleting route to 192.168.1.0/24 Oct 26 12:01:12 volumiolenn dhcpcd[882]: wlan0: deleting default route via 192.168.1.1 Oct 26 12:01:12 volumiolenn volumio[972]: info: Discovery: A device disappeared from network Oct 26 12:01:12 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:12+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: i/o timeout" Oct 26 12:01:12 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:12+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gue1.spotify.com: device or resource busy" Oct 26 12:01:12 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:12+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Oct 26 12:01:12 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:12+01:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Oct 26 12:01:12 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:12+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Oct 26 12:01:12 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:12+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Oct 26 12:01:12 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:12+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gue1.spotify.com: device or resource busy" Oct 26 12:01:12 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:12+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Oct 26 12:01:12 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:12+01:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Oct 26 12:01:13 volumiolenn ntpd[755]: Deleting interface #3 wlan0, 192.168.1.151#123, interface stats: received=174, sent=209, dropped=0, active_time=1094 secs Oct 26 12:01:13 volumiolenn ntpd[755]: 45.9.2.181 local addr 192.168.1.151 -> Oct 26 12:01:13 volumiolenn ntpd[755]: 80.90.61.27 local addr 192.168.1.151 -> Oct 26 12:01:13 volumiolenn ntpd[755]: 44.9.16.35 local addr 192.168.1.151 -> Oct 26 12:01:13 volumiolenn ntpd[755]: 44.9.16.66 local addr 192.168.1.151 -> Oct 26 12:01:13 volumiolenn ntpd[755]: 172.255.248.67 local addr 192.168.1.151 -> Oct 26 12:01:13 volumiolenn ntpd[755]: 162.159.200.1 local addr 192.168.1.151 -> Oct 26 12:01:13 volumiolenn ntpd[755]: 185.194.94.71 local addr 192.168.1.151 -> Oct 26 12:01:13 volumiolenn ntpd[755]: 83.171.216.34 local addr 192.168.1.151 -> Oct 26 12:01:13 volumiolenn ntpd[755]: 162.159.200.123 local addr 192.168.1.151 -> Oct 26 12:01:14 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:14+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Oct 26 12:01:14 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:14+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Oct 26 12:01:14 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:14+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gue1.spotify.com: device or resource busy" Oct 26 12:01:14 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:14+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Oct 26 12:01:14 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:14+01:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Oct 26 12:01:15 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:15+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Oct 26 12:01:15 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:15+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Oct 26 12:01:15 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:15+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gue1.spotify.com: device or resource busy" Oct 26 12:01:15 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:15+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Oct 26 12:01:15 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:15+01:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Oct 26 12:01:16 volumiolenn kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Oct 26 12:01:16 volumiolenn kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Oct 26 12:01:16 volumiolenn kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Oct 26 12:01:16 volumiolenn kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Oct 26 12:01:17 volumiolenn volumio[972]: info: Volumio Network Manager: Network status updated: 0 Oct 26 12:01:18 volumiolenn wpa_supplicant[870]: wlan0: Trying to associate with SSID 'wrecks' Oct 26 12:01:18 volumiolenn kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Oct 26 12:01:18 volumiolenn kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Oct 26 12:01:18 volumiolenn kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Oct 26 12:01:18 volumiolenn kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Oct 26 12:01:18 volumiolenn kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Oct 26 12:01:18 volumiolenn kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Oct 26 12:01:18 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:18+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Oct 26 12:01:18 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:18+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Oct 26 12:01:18 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:18+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gue1.spotify.com: device or resource busy" Oct 26 12:01:18 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:18+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Oct 26 12:01:18 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:18+01:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Oct 26 12:01:18 volumiolenn dhcpcd[882]: wlan0: carrier acquired Oct 26 12:01:18 volumiolenn wpa_supplicant[870]: wlan0: Associated with f0:b0:14:e8:30:69 Oct 26 12:01:18 volumiolenn wpa_supplicant[870]: wlan0: CTRL-EVENT-CONNECTED - Connection to f0:b0:14:e8:30:69 completed [id=0 id_str=] Oct 26 12:01:18 volumiolenn wpa_supplicant[870]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Oct 26 12:01:18 volumiolenn wpa_supplicant[870]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=LU Oct 26 12:01:18 volumiolenn dhcpcd[882]: wlan0: IAID eb:42:96:f6 Oct 26 12:01:18 volumiolenn dhcpcd[882]: wlan0: carrier lost Oct 26 12:01:18 volumiolenn dhcpcd[882]: wlan0: carrier acquired Oct 26 12:01:18 volumiolenn dhcpcd[882]: wlan0: IAID eb:42:96:f6 Oct 26 12:01:18 volumiolenn dhcpcd[882]: wlan0: rebinding lease of 192.168.1.151 Oct 26 12:01:18 volumiolenn dhcpcd[882]: wlan0: soliciting an IPv6 router Oct 26 12:01:18 volumiolenn nmbd[727]: [2025/10/26 12:01:18.759783, 0] ../source3/nmbd/nmbd.c:361(reload_interfaces) Oct 26 12:01:18 volumiolenn nmbd[727]: reload_interfaces: No subnets to listen to. Waiting.. Oct 26 12:01:22 volumiolenn dhcpcd[882]: wlan0: probing address 192.168.1.151/24 Oct 26 12:01:23 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:23+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Oct 26 12:01:23 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:23+01:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Oct 26 12:01:23 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:23+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gue1.spotify.com: device or resource busy" Oct 26 12:01:23 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:23+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Oct 26 12:01:23 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:23+01:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Oct 26 12:01:27 volumiolenn dhcpcd[882]: wlan0: leased 192.168.1.151 for 864000 seconds Oct 26 12:01:27 volumiolenn avahi-daemon[589]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.151. Oct 26 12:01:27 volumiolenn avahi-daemon[589]: New relevant interface wlan0.IPv4 for mDNS. Oct 26 12:01:27 volumiolenn dhcpcd[882]: wlan0: adding route to 192.168.1.0/24 Oct 26 12:01:27 volumiolenn avahi-daemon[589]: Registering new address record for 192.168.1.151 on wlan0.IPv4. Oct 26 12:01:27 volumiolenn dhcpcd[882]: wlan0: adding default route via 192.168.1.1 Oct 26 12:01:27 volumiolenn volumio[972]: info: Volumio Network Manager: Network status updated: 2 Oct 26 12:01:27 volumiolenn volumio[972]: verbose: New Socket.io Connection to 192.168.1.151 from 192.168.1.117 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 OPR/122.0.0.0 Engine version: 3 Transport: polling Total Clients: 5 Oct 26 12:01:27 volumiolenn volumio[972]: verbose: New Socket.io Connection to 192.168.1.151 from 192.168.1.117 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 OPR/122.0.0.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 26 12:01:28 volumiolenn volumio[972]: info: Discovery: adding 33fc3eea-f256-42d3-af71-de9c40e41ef1 Oct 26 12:01:28 volumiolenn volumio[972]: info: Discovery: Found device Volumio_Lenn Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:28 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:28 volumiolenn volumio[972]: verbose: New Socket.io Connection to 192.168.1.151 from 192.168.1.117 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 OPR/122.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:28 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:28 volumiolenn volumio[972]: info: Received Get System Info Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 12:01:28 volumiolenn volumio[972]: info: Discovery: Getting this device information Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:28 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:28 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetVisibleSources Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:28 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:28 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 26 12:01:28 volumiolenn volumio[972]: info: Received Get System Info Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 12:01:28 volumiolenn volumio[972]: info: Discovery: Getting this device information Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:28 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:28 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:28 volumiolenn volumio[972]: info: Listing playlists Oct 26 12:01:28 volumiolenn volumio[972]: info: Received Get System Info Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 12:01:28 volumiolenn volumio[972]: info: Discovery: Getting this device information Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:28 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 12:01:28 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:28 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetVisibleSources Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 26 12:01:29 volumiolenn volumio[972]: info: Received Get System Info Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 12:01:29 volumiolenn volumio[972]: info: Discovery: Getting this device information Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn ntpd[755]: Listen normally on 4 wlan0 192.168.1.151:123 Oct 26 12:01:29 volumiolenn ntpd[755]: new interface(s) found: waking up resolver Oct 26 12:01:29 volumiolenn volumio[972]: info: Listing playlists Oct 26 12:01:29 volumiolenn volumio[972]: info: Received Get System Info Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 12:01:29 volumiolenn volumio[972]: info: Discovery: Getting this device information Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetVisibleSources Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 26 12:01:29 volumiolenn volumio[972]: info: Received Get System Info Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 12:01:29 volumiolenn volumio[972]: info: Discovery: Getting this device information Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: Listing playlists Oct 26 12:01:29 volumiolenn volumio[972]: info: Received Get System Info Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 12:01:29 volumiolenn volumio[972]: info: Discovery: Getting this device information Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 12:01:29 volumiolenn volumio[972]: info: CoreCommandRouter::volumioGetState Oct 26 12:01:29 volumiolenn volumio[972]: info: CorePlayQueue::getTrack 0 Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=debug msg="completed keyexchange" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=debug msg="completed challenge" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=info msg="authenticated AP" username="vs*********************21" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=debug msg="re-established accesspoint connection" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=trace msg="received accesspoint ping" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Oct 26 12:01:30 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:30+01:00" level=trace msg="received accesspoint pong ack" Oct 26 12:01:34 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:35 volumiolenn volumio[972]: info: Enabling plugin now_playing Oct 26 12:01:35 volumiolenn volumio[972]: info: Loading plugin "now_playing"... Oct 26 12:01:36 volumiolenn volumio[972]: error: !!!! WARNING !!!! Oct 26 12:01:36 volumiolenn volumio[972]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Oct 26 12:01:36 volumiolenn volumio[972]: Require stack: Oct 26 12:01:36 volumiolenn volumio[972]: - /data/plugins/user_interface/now_playing/dist/index.js Oct 26 12:01:36 volumiolenn volumio[972]: - /volumio/app/pluginmanager.js Oct 26 12:01:36 volumiolenn volumio[972]: - /volumio/app/index.js Oct 26 12:01:36 volumiolenn volumio[972]: - /volumio/index.js Oct 26 12:01:36 volumiolenn volumio[972]: error: Stack trace: Error: Cannot find module 'geo-tz' Oct 26 12:01:36 volumiolenn volumio[972]: Require stack: Oct 26 12:01:36 volumiolenn volumio[972]: - /data/plugins/user_interface/now_playing/dist/index.js Oct 26 12:01:36 volumiolenn volumio[972]: - /volumio/app/pluginmanager.js Oct 26 12:01:36 volumiolenn volumio[972]: - /volumio/app/index.js Oct 26 12:01:36 volumiolenn volumio[972]: - /volumio/index.js Oct 26 12:01:36 volumiolenn volumio[972]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Oct 26 12:01:36 volumiolenn volumio[972]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Oct 26 12:01:36 volumiolenn volumio[972]: at Module.require (internal/modules/cjs/loader.js:952:19) Oct 26 12:01:36 volumiolenn volumio[972]: at require (internal/modules/cjs/helpers.js:88:18) Oct 26 12:01:36 volumiolenn volumio[972]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Oct 26 12:01:36 volumiolenn volumio[972]: at Module._compile (internal/modules/cjs/loader.js:1063:30) Oct 26 12:01:36 volumiolenn volumio[972]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) Oct 26 12:01:36 volumiolenn volumio[972]: at Module.load (internal/modules/cjs/loader.js:928:32) Oct 26 12:01:36 volumiolenn volumio[972]: at Function.Module._load (internal/modules/cjs/loader.js:769:14) Oct 26 12:01:36 volumiolenn volumio[972]: at Module.require (internal/modules/cjs/loader.js:952:19) Oct 26 12:01:36 volumiolenn volumio[972]: at require (internal/modules/cjs/helpers.js:88:18) Oct 26 12:01:36 volumiolenn volumio[972]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Oct 26 12:01:36 volumiolenn volumio[972]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Oct 26 12:01:36 volumiolenn volumio[972]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 26 12:01:36 volumiolenn volumio[972]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 26 12:01:36 volumiolenn volumio[972]: error: !!!! WARNING !!!! Oct 26 12:01:36 volumiolenn volumio[972]: info: Done. Oct 26 12:01:36 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:38 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:41 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:41 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:41+01:00" level=error msg="did not receive last pong from dealer, 330s passed" Oct 26 12:01:41 volumiolenn volumio[972]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 12:01:43 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:44 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 26 12:01:44 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 26 12:01:45 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:46 volumiolenn volumio[972]: info: Enabling plugin now_playing Oct 26 12:01:46 volumiolenn volumio[972]: info: Loading plugin "now_playing"... Oct 26 12:01:46 volumiolenn volumio[972]: error: !!!! WARNING !!!! Oct 26 12:01:46 volumiolenn volumio[972]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Oct 26 12:01:46 volumiolenn volumio[972]: Require stack: Oct 26 12:01:46 volumiolenn volumio[972]: - /data/plugins/user_interface/now_playing/dist/index.js Oct 26 12:01:46 volumiolenn volumio[972]: - /volumio/app/pluginmanager.js Oct 26 12:01:46 volumiolenn volumio[972]: - /volumio/app/index.js Oct 26 12:01:46 volumiolenn volumio[972]: - /volumio/index.js Oct 26 12:01:46 volumiolenn volumio[972]: error: Stack trace: Error: Cannot find module 'geo-tz' Oct 26 12:01:46 volumiolenn volumio[972]: Require stack: Oct 26 12:01:46 volumiolenn volumio[972]: - /data/plugins/user_interface/now_playing/dist/index.js Oct 26 12:01:46 volumiolenn volumio[972]: - /volumio/app/pluginmanager.js Oct 26 12:01:46 volumiolenn volumio[972]: - /volumio/app/index.js Oct 26 12:01:46 volumiolenn volumio[972]: - /volumio/index.js Oct 26 12:01:46 volumiolenn volumio[972]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Oct 26 12:01:46 volumiolenn volumio[972]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Oct 26 12:01:46 volumiolenn volumio[972]: at Module.require (internal/modules/cjs/loader.js:952:19) Oct 26 12:01:46 volumiolenn volumio[972]: at require (internal/modules/cjs/helpers.js:88:18) Oct 26 12:01:46 volumiolenn volumio[972]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Oct 26 12:01:46 volumiolenn volumio[972]: at Module._compile (internal/modules/cjs/loader.js:1063:30) Oct 26 12:01:46 volumiolenn volumio[972]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) Oct 26 12:01:46 volumiolenn volumio[972]: at Module.load (internal/modules/cjs/loader.js:928:32) Oct 26 12:01:46 volumiolenn volumio[972]: at Function.Module._load (internal/modules/cjs/loader.js:769:14) Oct 26 12:01:46 volumiolenn volumio[972]: at Module.require (internal/modules/cjs/loader.js:952:19) Oct 26 12:01:46 volumiolenn volumio[972]: at require (internal/modules/cjs/helpers.js:88:18) Oct 26 12:01:46 volumiolenn volumio[972]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Oct 26 12:01:46 volumiolenn volumio[972]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Oct 26 12:01:46 volumiolenn volumio[972]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 26 12:01:46 volumiolenn volumio[972]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 26 12:01:46 volumiolenn volumio[972]: error: !!!! WARNING !!!! Oct 26 12:01:46 volumiolenn volumio[972]: info: Error: TypeError: Cannot read property 'printToastMessage' of null Oct 26 12:01:47 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:49 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:51 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:51 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:51+01:00" level=debug msg="dealer connection opened" Oct 26 12:01:51 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:51+01:00" level=debug msg="re-established dealer connection" Oct 26 12:01:51 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:51+01:00" level=debug msg="received connection id: YjNlMTUxNTctY2Ix...RkU0RjRGQzdGQg==" Oct 26 12:01:51 volumiolenn go-librespot[1172]: time="2025-10-26T12:01:51+01:00" level=debug msg="put connect state because NEW_DEVICE" Oct 26 12:01:53 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:01:58 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:02:00 volumiolenn wpa_supplicant[870]: RRM: Ignoring radio measurement request: Not RRM network Oct 26 12:02:04 volumiolenn volumio[972]: info: Starting Uninstall of plugin user_interface - now_playing Oct 26 12:02:04 volumiolenn volumio[972]: info: Uninstalling plugin now_playing Oct 26 12:02:11 volumiolenn volumio[972]: info: Starting Uninstall of plugin user_interface - now_playing Oct 26 12:02:11 volumiolenn volumio[972]: info: Uninstalling plugin now_playing Oct 26 12:02:11 volumiolenn go-librespot[1172]: time="2025-10-26T12:02:11+01:00" level=trace msg="sent dealer ping" Oct 26 12:02:11 volumiolenn go-librespot[1172]: time="2025-10-26T12:02:11+01:00" level=trace msg="received dealer pong" Oct 26 12:02:23 volumiolenn volumio[972]: info: Starting Uninstall of plugin user_interface - now_playing Oct 26 12:02:23 volumiolenn volumio[972]: info: Uninstalling plugin now_playing Oct 26 12:02:24 volumiolenn ntpd[755]: Soliciting pool server 2606:4700:f1::123 Oct 26 12:02:25 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 26 12:02:25 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 26 12:02:26 volumiolenn ntpd[755]: Soliciting pool server 85.93.216.115 Oct 26 12:02:30 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 26 12:02:31 volumiolenn volumio[972]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 26 12:02:32 volumiolenn volumio[972]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/download/now_playing/0.7.6/volumio/buster/armhf Oct 26 12:02:32 volumiolenn volumio[972]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 12:02:32 volumiolenn volumio[972]: TypeError: Cannot read property 'broadcastMessage' of null Oct 26 12:02:32 volumiolenn volumio[972]: at /volumio/app/index.js:1534:32 Oct 26 12:02:32 volumiolenn volumio[972]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Oct 26 12:02:32 volumiolenn volumio[972]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Oct 26 12:02:32 volumiolenn volumio[972]: at CoreCommandRouter.broadcastMessage (/volumio/app/index.js:1532:13) Oct 26 12:02:32 volumiolenn volumio[972]: at PluginManager.pushMessage (/volumio/app/pluginmanager.js:1594:20) Oct 26 12:02:32 volumiolenn volumio[972]: at PluginManager.installPlugin (/volumio/app/pluginmanager.js:776:8) Oct 26 12:02:32 volumiolenn volumio[972]: at CoreCommandRouter.installPlugin (/volumio/app/index.js:1453:22) Oct 26 12:02:32 volumiolenn volumio[972]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1209:47) Oct 26 12:02:32 volumiolenn volumio[972]: at Socket.emit (events.js:315:20) Oct 26 12:02:32 volumiolenn volumio[972]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 26 12:02:32 volumiolenn volumio[972]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 26 12:02:32 volumiolenn volumio[972]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 12:02:32 volumiolenn sudo[5537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-26 12:01 Oct 26 12:02:32 volumiolenn sudo[5537]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"