Dec 08 18:31:08 volumiocasa wpa_supplicant[1380]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="VodafoneFamassacri" Dec 08 18:31:08 volumiocasa wpa_supplicant[1380]: MBO: Disable MBO/OCE due to misbehaving AP not having enabled PMF Dec 08 18:31:08 volumiocasa wpa_supplicant[1380]: wlan0: Trying to associate with 08:16:05:32:5c:26 (SSID='VodafoneFamassacri' freq=2422 MHz) Dec 08 18:31:08 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:08+01:00" level=error msg="did not receive last pong from dealer, 145s passed" Dec 08 18:31:08 volumiocasa wpa_supplicant[1380]: wlan0: Associated with 08:16:05:32:5c:26 Dec 08 18:31:08 volumiocasa wpa_supplicant[1380]: MBO: Disable MBO/OCE due to misbehaving AP not having enabled PMF Dec 08 18:31:08 volumiocasa wpa_supplicant[1380]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 08 18:31:08 volumiocasa wpa_supplicant[1380]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=IT Dec 08 18:31:08 volumiocasa wpa_supplicant[1380]: wlan0: WPA: Key negotiation completed with 08:16:05:32:5c:26 [PTK=CCMP GTK=TKIP] Dec 08 18:31:08 volumiocasa wpa_supplicant[1380]: wlan0: CTRL-EVENT-CONNECTED - Connection to 08:16:05:32:5c:26 completed [id=0 id_str=] Dec 08 18:31:08 volumiocasa dhcpcd[1062]: wlan0: carrier acquired Dec 08 18:31:08 volumiocasa dhcpcd[1062]: wlan0: IAID 9e:03:25:86 Dec 08 18:31:09 volumiocasa dhcpcd[1062]: wlan0: rebinding lease of 192.168.1.14 Dec 08 18:31:09 volumiocasa dhcpcd[1062]: wlan0: soliciting an IPv6 router Dec 08 18:31:10 volumiocasa nmbd[1272]: [2025/12/08 18:31:10.635985, 0] ../../source3/nmbd/nmbd.c:359(reload_interfaces) Dec 08 18:31:10 volumiocasa nmbd[1272]: reload_interfaces: No subnets to listen to. Waiting.. Dec 08 18:31:11 volumiocasa dhcpcd[1062]: wlan0: probing address 192.168.1.14/24 Dec 08 18:31:15 volumiocasa dhcpcd[1062]: wlan0: leased 192.168.1.14 for 86400 seconds Dec 08 18:31:15 volumiocasa avahi-daemon[1502]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.14. Dec 08 18:31:15 volumiocasa avahi-daemon[1502]: New relevant interface wlan0.IPv4 for mDNS. Dec 08 18:31:15 volumiocasa avahi-daemon[1502]: Registering new address record for 192.168.1.14 on wlan0.IPv4. Dec 08 18:31:15 volumiocasa dhcpcd[1062]: wlan0: adding route to 192.168.1.0/24 Dec 08 18:31:15 volumiocasa systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 08 18:31:15 volumiocasa systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 08 18:31:15 volumiocasa systemd[1]: welcome.service: Deactivated successfully. Dec 08 18:31:15 volumiocasa systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 08 18:31:15 volumiocasa systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 08 18:31:15 volumiocasa dhcpcd[1062]: wlan0: adding default route via 192.168.1.1 Dec 08 18:31:15 volumiocasa systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 08 18:31:15 volumiocasa welcome[2874]: Resolved ip:[1] 192.168.1.14 Dec 08 18:31:15 volumiocasa systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 08 18:31:15 volumiocasa systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 08 18:31:16 volumiocasa volumio[1503]: info: Volumio Network Manager: Network status updated: 2 Dec 08 18:31:16 volumiocasa volumio[1503]: info: Discovery: adding f39a3e87-6294-4b87-b2c2-77acb7026959 Dec 08 18:31:16 volumiocasa volumio[1503]: info: Discovery: Found device Volumiocasa Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:16 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 18:31:16 volumiocasa volumio[1503]: info: Discovery: Getting this device information Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:16 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 18:31:16 volumiocasa volumio[1503]: verbose: New Socket.io Connection to 192.168.1.14:3000 from 192.168.1.12 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 08 18:31:16 volumiocasa volumio[1503]: verbose: New Socket.io Connection to 192.168.1.14:3000 from 192.168.1.12 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 18:31:16 volumiocasa volumio[1503]: info: Discovery: Getting this device information Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:16 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:16 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 18:31:17 volumiocasa ntpd[1226]: IO: Listen normally on 4 wlan0 192.168.1.14:123 Dec 08 18:31:17 volumiocasa ntpd[1226]: IO: new interface(s) found: waking up resolver Dec 08 18:31:17 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 18:31:17 volumiocasa volumio[1503]: info: Received Get System Info Dec 08 18:31:17 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 18:31:17 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 18:31:17 volumiocasa volumio[1503]: info: Discovery: Getting this device information Dec 08 18:31:17 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:17 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:17 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 18:31:19 volumiocasa volumio[1503]: verbose: New Socket.io Connection to 192.168.1.14 from 192.168.1.12 UA: Mozilla/5.0 (Linux; Android 15; moto g85 5G Build/V1UOS35H.74-16-4-9; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/142.0.7444.171 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Dec 08 18:31:19 volumiocasa volumio[1503]: verbose: New Socket.io Connection to 192.168.1.14 from 192.168.1.12 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetVisibleSources Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 08 18:31:19 volumiocasa volumio[1503]: info: Received Get System Info Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 18:31:19 volumiocasa volumio[1503]: info: Discovery: Getting this device information Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: Listing playlists Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetQueue Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreStateMachine::getQueue Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getQueue Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetVisibleSources Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 08 18:31:19 volumiocasa volumio[1503]: info: Received Get System Info Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 18:31:19 volumiocasa volumio[1503]: info: Discovery: Getting this device information Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: Listing playlists Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 18:31:19 volumiocasa volumio[1503]: info: Received Get System Info Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 18:31:19 volumiocasa volumio[1503]: info: Discovery: Getting this device information Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 18:31:19 volumiocasa volumio[1503]: info: Received Get System Info Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 18:31:19 volumiocasa volumio[1503]: info: Discovery: Getting this device information Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 08 18:31:19 volumiocasa volumio[1503]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 08 18:31:19 volumiocasa volumio[1503]: info: Received Get System Version Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 18:31:19 volumiocasa volumio[1503]: info: Received Get System Info Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 18:31:19 volumiocasa volumio[1503]: info: Discovery: Getting this device information Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetVisibleSources Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 08 18:31:19 volumiocasa volumio[1503]: info: Received Get System Info Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 18:31:19 volumiocasa volumio[1503]: info: Discovery: Getting this device information Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioGetState Dec 08 18:31:19 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 6 Dec 08 18:31:19 volumiocasa volumio[1503]: info: Listing playlists Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 08 18:31:19 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 08 18:31:20 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 08 18:31:27 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:27+01:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.1.14:59636->34.158.1.133:4070: read: connection reset by peer" Dec 08 18:31:27 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 08 18:31:27 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:27+01:00" level=debug msg="completed keyexchange" Dec 08 18:31:27 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:27+01:00" level=debug msg="completed challenge" Dec 08 18:31:27 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:27+01:00" level=info msg="authenticated AP" username="9k*********************mk" Dec 08 18:31:27 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:27+01:00" level=debug msg="re-established accesspoint connection" Dec 08 18:31:27 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:27+01:00" level=trace msg="received accesspoint ping" Dec 08 18:31:27 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:27+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 08 18:31:27 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:27+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 08 18:31:28 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioNext Dec 08 18:31:28 volumiocasa volumio[1503]: info: CoreStateMachine::next Dec 08 18:31:28 volumiocasa volumio[1503]: info: CoreStateMachine::stop Dec 08 18:31:28 volumiocasa volumio[1503]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 08 18:31:28 volumiocasa volumio[1503]: info: CoreStateMachine::play index undefined Dec 08 18:31:28 volumiocasa volumio[1503]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 08 18:31:28 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 8 Dec 08 18:31:28 volumiocasa volumio[1503]: info: CoreStateMachine::startPlaybackTimer Dec 08 18:31:28 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 8 Dec 08 18:31:28 volumiocasa volumio[1503]: info: [1765215088223] ControllerSpotify::clearAddPlayTrack Dec 08 18:31:28 volumiocasa volumio[1503]: info: Sending Spotify command with payload to local API: /player/play Dec 08 18:31:28 volumiocasa volumio[1503]: info: CoreStateMachine::updateTrackBlock Dec 08 18:31:28 volumiocasa volumio[1503]: info: CorePlayQueue::getTrackBlock Dec 08 18:31:37 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 18:31:37 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 08 18:31:37 volumiocasa volumio[1503]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 18:31:37 volumiocasa volumio[1503]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 18:31:38 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:38+01:00" level=error msg="did not receive last pong from dealer, 175s passed" Dec 08 18:31:40 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:40+01:00" level=debug msg="put state request failed with status 400: Missing payload" Dec 08 18:31:41 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:41+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 08 18:31:41 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:41+01:00" level=trace msg="emitting websocket event: playing" Dec 08 18:31:41 volumiocasa volumio[1503]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:7b8CfC6saZb8CR2GQ76nqC","uri":"spotify:track:7b8CfC6saZb8CR2GQ76nqC","resume":false,"play_origin":"go-librespot"}} Dec 08 18:31:41 volumiocasa volumio[1503]: SPOTIFY: PUSH STATE SPOTIFY Dec 08 18:31:41 volumiocasa volumio[1503]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreCommandRouter::servicePushState Dec 08 18:31:41 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 8 Dec 08 18:31:41 volumiocasa volumio[1503]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 08 18:31:41 volumiocasa volumio[1503]: verbose: CURRENT POSITION 8 Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreStateMachine::syncState stateService play Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreStateMachine::syncState currentStatus stop Dec 08 18:31:41 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:41+01:00" level=debug msg="resolved context of track" uri="spotify:track:6JBsxkmMI6QaHTtpdlcc5z" Dec 08 18:31:41 volumiocasa go-librespot[2130]: time="2025-12-08T18:31:41+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:6JBsxkmMI6QaHTtpdlcc5z" Dec 08 18:31:41 volumiocasa volumio[1503]: SPOTIFY: PUSH STATE SPOTIFY Dec 08 18:31:41 volumiocasa volumio[1503]: SPOTIFY: {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreCommandRouter::servicePushState Dec 08 18:31:41 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 8 Dec 08 18:31:41 volumiocasa volumio[1503]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 08 18:31:41 volumiocasa volumio[1503]: verbose: CURRENT POSITION 8 Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreStateMachine::syncState stateService play Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreStateMachine::syncState currentStatus play Dec 08 18:31:41 volumiocasa volumio[1503]: info: Received an update from plugin. extracting info from payload Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreStateMachine::pushState Dec 08 18:31:41 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 8 Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioPushState Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreStateMachine::pushState Dec 08 18:31:41 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 8 Dec 08 18:31:41 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioPushState Dec 08 18:31:41 volumiocasa volumio[1503]: info: FusionDsp - Volumio is playing Dec 08 18:31:41 volumiocasa volumio[1503]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Dec 08 18:31:41 volumiocasa volumio[1503]: info: FusionDsp - Volumio is playing Dec 08 18:31:41 volumiocasa volumio[1503]: info: FusionDsp - Clipping Monitor started Dec 08 18:31:41 volumiocasa volumio[1503]: info: FusionDsp - Clipping Monitor started Dec 08 18:31:41 volumiocasa volumio[1503]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 08 18:32:06 volumiocasa go-librespot[2130]: time="2025-12-08T18:32:06+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 18:32:06 volumiocasa volumio[1503]: info: Disabling plugin spop Dec 08 18:32:06 volumiocasa sudo[2988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Dec 08 18:32:06 volumiocasa volumio[1503]: info: Done. Dec 08 18:32:06 volumiocasa sudo[2988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 18:32:06 volumiocasa volumio[1503]: info: Connection to go-librespot Websocket closed Dec 08 18:32:06 volumiocasa systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 08 18:32:06 volumiocasa systemd[1]: go-librespot-daemon.service: Killing process 2132 (go-librespot) with signal SIGKILL. Dec 08 18:32:06 volumiocasa systemd[1]: go-librespot-daemon.service: Killing process 2133 (go-librespot) with signal SIGKILL. Dec 08 18:32:06 volumiocasa systemd[1]: go-librespot-daemon.service: Killing process 2140 (go-librespot) with signal SIGKILL. Dec 08 18:32:06 volumiocasa systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 08 18:32:06 volumiocasa volumio[1503]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Dec 08 18:32:06 volumiocasa systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 18:32:06 volumiocasa systemd[1]: go-librespot-daemon.service: Consumed 5min 34.934s CPU time. Dec 08 18:32:06 volumiocasa systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 08 18:32:06 volumiocasa systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 08 18:32:06 volumiocasa systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 08 18:32:06 volumiocasa systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 08 18:32:06 volumiocasa sudo[2988]: pam_unix(sudo:session): session closed for user root Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioPause Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreStateMachine::pause Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreStateMachine::stPlaybackTimer Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreStateMachine::servicePause Dec 08 18:32:06 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 8 Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreCommandRouter::servicePause Dec 08 18:32:06 volumiocasa volumio[1503]: error: WARNING: No pause method for service spop Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioNext Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreStateMachine::next Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreStateMachine::stop Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreStateMachine::updateTrackBlock Dec 08 18:32:06 volumiocasa volumio[1503]: info: CorePlayQueue::getTrackBlock Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreStateMachine::stPlaybackTimer Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreStateMachine::pushState Dec 08 18:32:06 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 8 Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreCommandRouter::volumioPushState Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreStateMachine::serviceStop Dec 08 18:32:06 volumiocasa volumio[1503]: info: CorePlayQueue::getTrack 8 Dec 08 18:32:06 volumiocasa volumio[1503]: info: CoreCommandRouter::serviceStop Dec 08 18:32:06 volumiocasa volumio[1503]: error: WARNING: No stop method for service spop Dec 08 18:32:06 volumiocasa volumio[1503]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 08 18:32:06 volumiocasa volumio[1503]: TypeError: Cannot read properties of undefined (reading 'then') Dec 08 18:32:06 volumiocasa volumio[1503]: at CoreStateMachine.next (/volumio/app/statemachine.js:1181:9) Dec 08 18:32:06 volumiocasa volumio[1503]: at CoreCommandRouter.volumioNext (/volumio/app/index.js:103:28) Dec 08 18:32:06 volumiocasa volumio[1503]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:274:26) Dec 08 18:32:06 volumiocasa volumio[1503]: at Socket.emit (node:events:514:28) Dec 08 18:32:06 volumiocasa volumio[1503]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Dec 08 18:32:06 volumiocasa volumio[1503]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 08 18:32:06 volumiocasa volumio[1503]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 08 18:32:06 volumiocasa sudo[3020]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-08 18:31' Dec 08 18:32:06 volumiocasa sudo[3020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"