Jan 13 21:52:03 volumio volumio[1223]: verbose: New Socket.io Connection to 192.168.0.103:3000 from 192.168.0.104 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Jan 13 21:52:03 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:52:03 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:52:03 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:52:03 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:52:03 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:03 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:52:47 volumio sudo[15028]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 21:52:47 volumio sudo[15028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 21:52:47 volumio sudo[15028]: pam_unix(sudo:session): session closed for user root Jan 13 21:52:47 volumio sudo[15030]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 21:52:47 volumio sudo[15030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 21:52:47 volumio sudo[15030]: pam_unix(sudo:session): session closed for user root Jan 13 21:52:47 volumio volumio[1223]: verbose: New Socket.io Connection to 192.168.0.103 from 192.168.0.102 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Edg/143.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::volumioGetVisibleSources Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:52:48 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 13 21:52:48 volumio volumio[1223]: info: Received Get System Info Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:52:48 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:52:48 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:52:48 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:48 volumio volumio[1223]: info: Listing playlists Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 13 21:52:48 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 13 21:52:49 volumio sudo[15034]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 21:52:49 volumio sudo[15034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 21:52:49 volumio sudo[15036]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 21:52:49 volumio sudo[15036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 21:52:49 volumio sudo[15034]: pam_unix(sudo:session): session closed for user root Jan 13 21:52:49 volumio sudo[15036]: pam_unix(sudo:session): session closed for user root Jan 13 21:52:49 volumio volumio[1223]: verbose: New Socket.io Connection to 192.168.0.103 from 192.168.0.102 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Edg/143.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::volumioGetVisibleSources Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:52:49 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 13 21:52:49 volumio volumio[1223]: info: Received Get System Info Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:52:49 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:52:49 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:52:49 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:49 volumio volumio[1223]: info: Listing playlists Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 13 21:52:49 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 13 21:52:50 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:52:50 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:50 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 13 21:52:51 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 13 21:52:51 volumio volumio[1223]: info: Received Get System Info Jan 13 21:52:51 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:52:51 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:52:51 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:52:51 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:52:51 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:51 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:52:51 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 13 21:52:51 volumio volumio[1223]: info: Received Get System Info Jan 13 21:52:51 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:52:51 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:52:51 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:52:51 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:52:51 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:51 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:52:55 volumio volumio[1223]: info: CoreCommandRouter::volumioPlay Jan 13 21:52:55 volumio volumio[1223]: info: CoreStateMachine::play index undefined Jan 13 21:52:55 volumio volumio[1223]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 13 21:52:55 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:55 volumio volumio[1223]: info: CoreStateMachine::startPlaybackTimer Jan 13 21:52:55 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:55 volumio volumio[1223]: info: [1768337575433] ControllerSpotify::clearAddPlayTrack Jan 13 21:52:55 volumio volumio[1223]: info: Sending Spotify command with payload to local API: /player/play Jan 13 21:52:59 volumio volumio[1223]: info: CoreCommandRouter::volumioPlay Jan 13 21:52:59 volumio volumio[1223]: info: CoreStateMachine::play index undefined Jan 13 21:52:59 volumio volumio[1223]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 13 21:52:59 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:59 volumio volumio[1223]: info: CoreStateMachine::startPlaybackTimer Jan 13 21:52:59 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:52:59 volumio volumio[1223]: info: [1768337579056] ControllerSpotify::clearAddPlayTrack Jan 13 21:52:59 volumio volumio[1223]: info: Sending Spotify command with payload to local API: /player/play Jan 13 21:52:59 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 13 21:53:01 volumio volumio[1223]: info: CoreCommandRouter::volumioGetQueue Jan 13 21:53:01 volumio volumio[1223]: info: CoreStateMachine::getQueue Jan 13 21:53:01 volumio volumio[1223]: info: CorePlayQueue::getQueue Jan 13 21:53:05 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:05 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:07 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 13 21:53:07 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 13 21:53:07 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 13 21:53:07 volumio volumio[1223]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 13 21:53:07 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 13 21:53:07 volumio volumio[1223]: info: Received Get System Version Jan 13 21:53:07 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 21:53:07 volumio volumio[1223]: info: Received Get System Info Jan 13 21:53:07 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:53:07 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:53:07 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:53:07 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:07 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:07 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:53:12 volumio volumio[1223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 13 21:53:16 volumio volumio[1223]: info: Received OAUTH Data Jan 13 21:53:16 volumio volumio[1223]: info: Executing Spotify Oauth Login Jan 13 21:53:16 volumio volumio[1223]: info: Saving Spotify Refresh Token Jan 13 21:53:16 volumio volumio[1223]: info: New Spotify access tokenBQAw6CI7M5... Jan 13 21:53:16 volumio volumio[1223]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 13 21:53:16 volumio sudo[15073]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 21:53:16 volumio sudo[15073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 21:53:16 volumio sudo[15073]: pam_unix(sudo:session): session closed for user root Jan 13 21:53:16 volumio sudo[15075]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 21:53:16 volumio sudo[15075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 21:53:16 volumio sudo[15075]: pam_unix(sudo:session): session closed for user root Jan 13 21:53:16 volumio volumio[1223]: verbose: New Socket.io Connection to 192.168.0.103 from 192.168.0.102 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Edg/143.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 13 21:53:16 volumio volumio[1223]: SPOTIFY: User informations: {"country":"HU","display_name":"GyJ","email":"gyorgyjozsi83@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ncg65vpz33y34numh6pjkj7gpu"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ncg65vpz33y34numh6pjkj7gpu","id":"31ncg65vpz33y34numh6pjkj7gpu","images":[],"product":"premium","type":"user","uri":"spotify:user:31ncg65vpz33y34numh6pjkj7gpu"} Jan 13 21:53:16 volumio volumio[1223]: info: Creating Spotify config file Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 21:53:16 volumio volumio[1223]: info: Spotify config file written Jan 13 21:53:16 volumio sudo[15081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 13 21:53:16 volumio sudo[15081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 21:53:16 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 13 21:53:16 volumio systemd[1]: go-librespot-daemon.service: Killing process 14611 (go-librespot) with signal SIGKILL. Jan 13 21:53:16 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 13 21:53:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 21:53:16 volumio volumio[1223]: info: Connection to go-librespot Websocket closed Jan 13 21:53:16 volumio volumio[1223]: info: Connection to go-librespot Websocket closed Jan 13 21:53:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 21:53:16 volumio go-librespot[15087]: go-librespot daemon starting... Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::volumioGetVisibleSources Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:16 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 13 21:53:16 volumio volumio[1223]: info: Received Get System Info Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:53:16 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:16 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:53:16 volumio sudo[15081]: pam_unix(sudo:session): session closed for user root Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:16 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:16 volumio volumio[1223]: info: Listing playlists Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 13 21:53:16 volumio go-librespot[15100]: time="2026-01-13T21:53:16+01:00" level=info msg="running go-librespot 0.6.2" Jan 13 21:53:16 volumio go-librespot[15100]: time="2026-01-13T21:53:16+01:00" level=debug msg="app state loaded" Jan 13 21:53:16 volumio go-librespot[15100]: time="2026-01-13T21:53:16+01:00" level=debug msg="stored credentials not found" Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 13 21:53:16 volumio go-librespot[15100]: time="2026-01-13T21:53:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 21:53:16 volumio volumio[1223]: info: New Spotify access tokenBQAdzMT1CU... Jan 13 21:53:16 volumio volumio[1223]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 13 21:53:16 volumio volumio[1223]: SPOTIFY: User informations: {"country":"HU","display_name":"GyJ","email":"gyorgyjozsi83@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ncg65vpz33y34numh6pjkj7gpu"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ncg65vpz33y34numh6pjkj7gpu","id":"31ncg65vpz33y34numh6pjkj7gpu","images":[],"product":"premium","type":"user","uri":"spotify:user:31ncg65vpz33y34numh6pjkj7gpu"} Jan 13 21:53:16 volumio volumio[1223]: info: Spotify Successfully logged in Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 13 21:53:16 volumio volumio[1223]: info: [1768337596800] CoreMusicLibrary::Adding element Spotify Jan 13 21:53:16 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 21:53:16 volumio volumio[1223]: Cannot find translation for source Spotify Jan 13 21:53:16 volumio go-librespot[15100]: time="2026-01-13T21:53:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 21:53:16 volumio go-librespot[15100]: time="2026-01-13T21:53:16+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 13 21:53:16 volumio go-librespot[15100]: time="2026-01-13T21:53:16+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 13 21:53:16 volumio go-librespot[15100]: time="2026-01-13T21:53:16+01:00" level=info msg="zeroconf server listening on port 40133" Jan 13 21:53:17 volumio go-librespot[15100]: time="2026-01-13T21:53:17+01:00" level=debug msg="obtained new client token: AAA3LOhbZD8nujZzl9Cul7ohKlKgOH9E9lTPyF4nbrkrVwRoeew5QIFq8h0Wa/r49XU/KHMckOv31kXjZVXwjF9/+/StzX8v1oJCmJi+6dmW8XnbyGI5X1KhwIpMxDK+Va2AHN6VoLfJPrvQEslygnkGCnF8xxh5iVcWn7/zd7zSEiMVpPSafsOkdOMoRm0uCkuss4LYp8llIXS4hlfJ/typceh9RvWXYfqonlNQpDnNgTX/OBIOzACp" Jan 13 21:53:17 volumio go-librespot[15100]: time="2026-01-13T21:53:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 13 21:53:17 volumio go-librespot[15100]: time="2026-01-13T21:53:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.0.103:37876->104.199.65.9:4070: read: connection reset by peer" Jan 13 21:53:17 volumio go-librespot[15100]: time="2026-01-13T21:53:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 13 21:53:17 volumio go-librespot[15100]: time="2026-01-13T21:53:17+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.0.103:44656->104.199.65.9:443: read: connection reset by peer" Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 13 21:53:18 volumio volumio[1223]: info: Received Get System Info Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:53:18 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:18 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:53:18 volumio go-librespot[15100]: time="2026-01-13T21:53:18+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 13 21:53:18 volumio go-librespot[15100]: time="2026-01-13T21:53:18+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 13 21:53:18 volumio volumio[1223]: info: Received Get System Info Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:53:18 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:18 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:18 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="completed keyexchange" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="completed challenge" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=info msg="authenticated AP" username="31************************pu" Jan 13 21:53:19 volumio volumio[1223]: info: Initializing connection to go-librespot Websocket Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="new websocket client" Jan 13 21:53:19 volumio volumio[1223]: info: Connection to go-librespot Websocket established Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=info msg="authenticated Login5" username="31************************pu" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="stored credentials" username="31************************pu" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="initializing zeroconf session" username="31************************pu" Jan 13 21:53:19 volumio volumio[1223]: info: go-librespot daemon successfully initialized Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="dealer connection opened" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=trace msg="starting accesspoint recv loop" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=trace msg="starting dealer recv loop" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=trace msg="received accesspoint ping" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="received connection id: Zjc2NzU5YTctOWFm...N0FDOTEyRDI2RA==" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=trace msg="received accesspoint pong ack" Jan 13 21:53:19 volumio go-librespot[15100]: time="2026-01-13T21:53:19+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 13 21:53:21 volumio volumio[1223]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 13 21:53:21 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 13 21:53:21 volumio volumio[1223]: info: Creating Spotify config file Jan 13 21:53:21 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 21:53:21 volumio volumio[1223]: info: Spotify config file written Jan 13 21:53:21 volumio sudo[15113]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 13 21:53:21 volumio sudo[15113]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 21:53:21 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 13 21:53:21 volumio systemd[1]: go-librespot-daemon.service: Killing process 15108 (go-librespot) with signal SIGKILL. Jan 13 21:53:21 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 13 21:53:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 21:53:21 volumio volumio[1223]: info: Connection to go-librespot Websocket closed Jan 13 21:53:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 21:53:21 volumio sudo[15113]: pam_unix(sudo:session): session closed for user root Jan 13 21:53:21 volumio go-librespot[15115]: go-librespot daemon starting... Jan 13 21:53:21 volumio go-librespot[15116]: time="2026-01-13T21:53:21+01:00" level=info msg="running go-librespot 0.6.2" Jan 13 21:53:21 volumio go-librespot[15116]: time="2026-01-13T21:53:21+01:00" level=debug msg="app state loaded" Jan 13 21:53:21 volumio go-librespot[15116]: time="2026-01-13T21:53:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 21:53:22 volumio go-librespot[15116]: time="2026-01-13T21:53:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 21:53:22 volumio go-librespot[15116]: time="2026-01-13T21:53:22+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 13 21:53:22 volumio go-librespot[15116]: time="2026-01-13T21:53:22+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 13 21:53:22 volumio go-librespot[15116]: time="2026-01-13T21:53:22+01:00" level=info msg="zeroconf server listening on port 38241" Jan 13 21:53:22 volumio go-librespot[15116]: time="2026-01-13T21:53:22+01:00" level=debug msg="obtained new client token: AABy+lKwfiIwc9xfKKrlRluFK0AWMmgTprTZyxDEffej1SIjQ/3nJ80ceXl5/+q99n2zOZcO2XGKr69N7kKTuZCsv4kl6fObGRo90V6hWdVrQ2VB3Sbw5ONIyEV9nBGlJRYjFV8UwjPFAedeEwe67I39/5kGr4dCEXWgDjtEol2RR190daAcAkyWGGTxrUyq2OU2TadyaW6pLQUShBz4zvHzS+Ruh5iUYdrLVRVqbL5k9QOpp1HiqQ==" Jan 13 21:53:22 volumio go-librespot[15116]: time="2026-01-13T21:53:22+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 13 21:53:22 volumio go-librespot[15116]: time="2026-01-13T21:53:22+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.0.103:37892->104.199.65.9:4070: read: connection reset by peer" Jan 13 21:53:22 volumio volumio[1223]: info: Getting Spotify volume Jan 13 21:53:22 volumio volumio[1223]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jan 13 21:53:22 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:22 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:22 volumio volumio[1223]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Jan 13 21:53:22 volumio volumio[1223]: info: Initializing connection to go-librespot Websocket Jan 13 21:53:22 volumio go-librespot[15116]: time="2026-01-13T21:53:22+01:00" level=debug msg="new websocket client" Jan 13 21:53:22 volumio volumio[1223]: info: Connection to go-librespot Websocket established Jan 13 21:53:22 volumio go-librespot[15116]: time="2026-01-13T21:53:22+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 13 21:53:22 volumio go-librespot[15116]: time="2026-01-13T21:53:22+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.0.103:48440->104.199.65.9:443: read: connection reset by peer" Jan 13 21:53:23 volumio go-librespot[15116]: time="2026-01-13T21:53:23+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 13 21:53:23 volumio go-librespot[15116]: time="2026-01-13T21:53:23+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 13 21:53:24 volumio volumio[1223]: info: CoreCommandRouter::volumioPlay Jan 13 21:53:24 volumio volumio[1223]: info: CoreStateMachine::play index undefined Jan 13 21:53:24 volumio volumio[1223]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 13 21:53:24 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:24 volumio volumio[1223]: info: CoreStateMachine::startPlaybackTimer Jan 13 21:53:24 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:24 volumio volumio[1223]: info: [1768337604058] ControllerSpotify::clearAddPlayTrack Jan 13 21:53:24 volumio volumio[1223]: info: Sending Spotify command with payload to local API: /player/play Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=debug msg="completed keyexchange" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=debug msg="completed challenge" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=info msg="authenticated AP" username="31************************pu" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=info msg="authenticated Login5" username="31************************pu" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=debug msg="initializing zeroconf session" username="31************************pu" Jan 13 21:53:24 volumio volumio[1223]: info: Initializing connection to go-librespot Websocket Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=debug msg="new websocket client" Jan 13 21:53:24 volumio volumio[1223]: info: Connection to go-librespot Websocket established Jan 13 21:53:24 volumio volumio[1223]: info: go-librespot daemon successfully initialized Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=debug msg="dealer connection opened" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=trace msg="starting accesspoint recv loop" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=trace msg="starting dealer recv loop" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=trace msg="received accesspoint ping" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 13 21:53:24 volumio volumio[1223]: info: Spotify volume: 100 Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=debug msg="resolved context of track" uri="spotify:track:1di1BEgJYzPvXUuinsYJGP" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1di1BEgJYzPvXUuinsYJGP" Jan 13 21:53:24 volumio go-librespot[15116]: time="2026-01-13T21:53:24+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1di1BEgJYzPvXUuinsYJGP" Jan 13 21:53:25 volumio go-librespot[15116]: time="2026-01-13T21:53:25+01:00" level=debug msg="put state request failed with status 400: Require at least one of callback url or connection id" Jan 13 21:53:25 volumio volumio[1223]: info: Getting Spotify volume Jan 13 21:53:25 volumio volumio[1223]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jan 13 21:53:25 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:25 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:25 volumio volumio[1223]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Jan 13 21:53:25 volumio volumio[1223]: SPOTIFY: SPOTIFY VOLUME 100 Jan 13 21:53:25 volumio volumio[1223]: SPOTIFY: VOLUMIO VOLUME 31 Jan 13 21:53:25 volumio volumio[1223]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 13 21:53:25 volumio volumio[1223]: info: Setting Spotify Volume from Volumio: 31 Jan 13 21:53:26 volumio go-librespot[15116]: time="2026-01-13T21:53:26+01:00" level=debug msg="put state request failed with status 400: Require at least one of callback url or connection id" Jan 13 21:53:26 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 13 21:53:27 volumio go-librespot[15116]: time="2026-01-13T21:53:27+01:00" level=debug msg="put state request failed with status 400: Require at least one of callback url or connection id" Jan 13 21:53:27 volumio go-librespot[15116]: time="2026-01-13T21:53:27+01:00" level=error msg="failed put state after update" error="put state request failed with status 400: Require at least one of callback url or connection id" Jan 13 21:53:27 volumio go-librespot[15116]: time="2026-01-13T21:53:27+01:00" level=trace msg="emitting websocket event: will_play" Jan 13 21:53:27 volumio volumio[1223]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1di1BEgJYzPvXUuinsYJGP","uri":"spotify:track:1di1BEgJYzPvXUuinsYJGP","play_origin":"go-librespot"}} Jan 13 21:53:27 volumio volumio[1223]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1di1BEgJYzPvXUuinsYJGP","uri":"spotify:track:1di1BEgJYzPvXUuinsYJGP","play_origin":"go-librespot"}} Jan 13 21:53:27 volumio volumio[1223]: SPOTIFY: SETTING SPOTIFY VOLUME 31 Jan 13 21:53:27 volumio volumio[1223]: info: Sending Spotify command with payload to local API: /player/volume Jan 13 21:53:27 volumio go-librespot[15116]: time="2026-01-13T21:53:27+01:00" level=debug msg="selected format OGG_VORBIS_320 (19354ab417462ed85198c518f818b4e9c6fb8637)" uri="spotify:track:1di1BEgJYzPvXUuinsYJGP" Jan 13 21:53:27 volumio go-librespot[15116]: time="2026-01-13T21:53:27+01:00" level=debug msg="requested aes key for file 19354ab417462ed85198c518f818b4e9c6fb8637, gid: 1di1BEgJYzPvXUuinsYJGP" Jan 13 21:53:27 volumio volumio[1223]: info: Getting Spotify volume Jan 13 21:53:27 volumio volumio[1223]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jan 13 21:53:27 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:27 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:27 volumio volumio[1223]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Jan 13 21:53:27 volumio volumio[1223]: info: Initializing connection to go-librespot Websocket Jan 13 21:53:27 volumio go-librespot[15116]: time="2026-01-13T21:53:27+01:00" level=debug msg="new websocket client" Jan 13 21:53:27 volumio volumio[1223]: info: Connection to go-librespot Websocket established Jan 13 21:53:28 volumio volumio[1223]: verbose: New Socket.io Connection to 192.168.0.103 from 192.168.0.102 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Edg/143.0.0.0 Engine version: 3 Transport: polling Total Clients: 8 Jan 13 21:53:28 volumio volumio[1223]: info: Received Get System Info Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:53:28 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:28 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:28 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::volumioGetVisibleSources Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:28 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 13 21:53:28 volumio volumio[1223]: info: Received Get System Info Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:53:28 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:28 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:28 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:28 volumio volumio[1223]: info: Listing playlists Jan 13 21:53:28 volumio volumio[1223]: verbose: New Socket.io Connection to 192.168.0.103:3000 from 192.168.0.104 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 21:53:28 volumio volumio[1223]: info: Discovery: Getting this device information Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:28 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 13 21:53:28 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 13 21:53:30 volumio volumio[1223]: info: Getting Spotify volume Jan 13 21:53:30 volumio volumio[1223]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jan 13 21:53:30 volumio volumio[1223]: info: CoreCommandRouter::volumioGetState Jan 13 21:53:30 volumio volumio[1223]: info: CorePlayQueue::getTrack 4 Jan 13 21:53:30 volumio volumio[1223]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Jan 13 21:53:33 volumio volumio[1223]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 13 21:53:33 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 13 21:53:33 volumio volumio[1223]: info: Creating Spotify config file Jan 13 21:53:33 volumio volumio[1223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 21:53:33 volumio volumio[1223]: info: Spotify config file written Jan 13 21:53:33 volumio sudo[15142]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 13 21:53:33 volumio sudo[15142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 13 21:53:33 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 13 21:53:33 volumio systemd[1]: go-librespot-daemon.service: Killing process 15124 (go-librespot) with signal SIGKILL. Jan 13 21:53:33 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 13 21:53:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 13 21:53:34 volumio volumio[1223]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 21:53:34 volumio volumio[1223]: Error: socket hang up Jan 13 21:53:34 volumio volumio[1223]: at connResetException (node:internal/errors:720:14) Jan 13 21:53:34 volumio volumio[1223]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 13 21:53:34 volumio volumio[1223]: at Socket.emit (node:events:526:35) Jan 13 21:53:34 volumio volumio[1223]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 13 21:53:34 volumio volumio[1223]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 13 21:53:34 volumio volumio[1223]: code: 'ECONNRESET', Jan 13 21:53:34 volumio volumio[1223]: response: undefined Jan 13 21:53:34 volumio volumio[1223]: } Jan 13 21:53:34 volumio volumio[1223]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 21:53:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 13 21:53:34 volumio go-librespot[15144]: go-librespot daemon starting... Jan 13 21:53:34 volumio sudo[15142]: pam_unix(sudo:session): session closed for user root Jan 13 21:53:34 volumio go-librespot[15156]: time="2026-01-13T21:53:34+01:00" level=info msg="running go-librespot 0.6.2" Jan 13 21:53:34 volumio go-librespot[15156]: time="2026-01-13T21:53:34+01:00" level=debug msg="app state loaded" Jan 13 21:53:34 volumio go-librespot[15156]: time="2026-01-13T21:53:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 13 21:53:34 volumio go-librespot[15156]: time="2026-01-13T21:53:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 21:53:34 volumio go-librespot[15156]: time="2026-01-13T21:53:34+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 13 21:53:34 volumio go-librespot[15156]: time="2026-01-13T21:53:34+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 13 21:53:34 volumio go-librespot[15156]: time="2026-01-13T21:53:34+01:00" level=info msg="zeroconf server listening on port 33351" Jan 13 21:53:34 volumio go-librespot[15156]: time="2026-01-13T21:53:34+01:00" level=debug msg="obtained new client token: AABn0l0sxPXxuMgF4bBmPPMC2LrQBnEXV/wyxdfv5vqhMVH1wSGyp2NYIXM8kpWm1mQ/28UKLmNKYCVZIAfNIr6eMXk0FHeJdOBcnrFJ0fbhVqohsoRksTK8kD06lnBZw7L8T5Z0//Q1mFqgKJKc/kXJDMrXgKr0NXyuNtM+fpRJoadK7AzFTVq/QRlwda8S4Hh020Bw5PE7HXmFvEazvJu83KG7O78kfWrRfFK8Rv5bGXj1J2VlQzjZ" Jan 13 21:53:34 volumio go-librespot[15156]: time="2026-01-13T21:53:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 13 21:53:34 volumio go-librespot[15156]: time="2026-01-13T21:53:34+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 13 21:53:34 volumio sudo[15167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-13 21:52' Jan 13 21:53:34 volumio sudo[15167]: 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"