Dec 05 17:45:04 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 05 17:45:04 volumio-aras volumio[1352]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 05 17:45:04 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 05 17:45:04 volumio-aras volumio[1352]: info: Received Get System Version Dec 05 17:45:04 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 17:45:04 volumio-aras volumio[1352]: info: Received Get System Info Dec 05 17:45:04 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 17:45:04 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 17:45:04 volumio-aras volumio[1352]: info: Discovery: Getting this device information Dec 05 17:45:04 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetState Dec 05 17:45:04 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 17:45:07 volumio-aras volumio[1352]: error: [LastFM] plugin is not authenticated, please retry Dec 05 17:45:09 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:09+01:00" level=debug msg="skipping dealer message" uri="hm://collection/collection/martinklimatech" Dec 05 17:45:09 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:09+01:00" level=debug msg="skipping dealer message" uri="hm://collection/collection/martinklimatech/json" Dec 05 17:45:09 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:09+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 245" Dec 05 17:45:09 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:09+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 325" Dec 05 17:45:09 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:09+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1F5p3rmiWPIYgZ" Dec 05 17:45:09 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:09+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Dec 05 17:45:12 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:12+01:00" level=debug msg="skipping dealer message" uri="hm://collection/collection/martinklimatech/json" Dec 05 17:45:12 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:12+01:00" level=debug msg="skipping dealer message" uri="hm://collection/collection/martinklimatech" Dec 05 17:45:12 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:12+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 315" Dec 05 17:45:12 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:12+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Dec 05 17:45:12 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:12+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1F5p3rmiWPIYgZ" Dec 05 17:45:12 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:12+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Dec 05 17:45:17 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:17+01:00" level=trace msg="sent dealer ping" Dec 05 17:45:17 volumio-aras go-librespot[5064]: time="2025-12-05T17:45:17+01:00" level=trace msg="received dealer pong" Dec 05 17:45:38 volumio-aras volumio[1352]: info: CALLMETHOD: music_service spop logout Dec 05 17:45:38 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: spop , logout Dec 05 17:45:38 volumio-aras volumio[1352]: info: Deleting Spotify credentials File Dec 05 17:45:38 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Dec 05 17:45:38 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 17:45:38 volumio-aras volumio[1352]: Cannot find translation for source Bandcamp Discover Dec 05 17:45:38 volumio-aras volumio[1352]: Cannot find translation for source YouTube2 Dec 05 17:45:38 volumio-aras volumio[1352]: Cannot find translation for source YouTube Music Dec 05 17:45:38 volumio-aras volumio[1352]: Cannot find translation for source 80s80s Radio Dec 05 17:45:38 volumio-aras volumio[1352]: Cannot find translation for source Controradio Dec 05 17:45:38 volumio-aras volumio[1352]: Cannot find translation for source RADIO 357 Dec 05 17:45:38 volumio-aras volumio[1352]: Cannot find translation for source Radio Paradise Dec 05 17:45:38 volumio-aras volumio[1352]: Cannot find translation for source Volusonic Dec 05 17:45:38 volumio-aras volumio[1352]: Cannot find translation for source LastFM Dec 05 17:45:38 volumio-aras volumio[1352]: Cannot find translation for source FM/DAB Radio Dec 05 17:45:39 volumio-aras volumio[1352]: info: Creating Spotify config file Dec 05 17:45:39 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 17:45:39 volumio-aras volumio[1352]: info: Spotify config file written Dec 05 17:45:39 volumio-aras sudo[5182]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 05 17:45:39 volumio-aras sudo[5182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:45:39 volumio-aras systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 05 17:45:39 volumio-aras systemd[1]: go-librespot-daemon.service: Killing process 5067 (go-librespot) with signal SIGKILL. Dec 05 17:45:39 volumio-aras systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 05 17:45:39 volumio-aras systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:45:39 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket closed Dec 05 17:45:39 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket closed Dec 05 17:45:39 volumio-aras systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:45:39 volumio-aras sudo[5182]: pam_unix(sudo:session): session closed for user root Dec 05 17:45:39 volumio-aras go-librespot[5185]: go-librespot daemon starting... Dec 05 17:45:39 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:39+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 17:45:39 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:39+01:00" level=debug msg="no app state found" Dec 05 17:45:39 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:39+01:00" level=debug msg="stored credentials not found" Dec 05 17:45:39 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:39+01:00" level=info msg="generated new device id: ce6f1960e4f434d9a156ee6b8b3be315f24dbcd0" Dec 05 17:45:39 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 17:45:39 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 05 17:45:39 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 05 17:45:39 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 05 17:45:39 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:39+01:00" level=info msg="zeroconf server listening on port 41035" Dec 05 17:45:42 volumio-aras volumio[1352]: info: Initializing connection to go-librespot Websocket Dec 05 17:45:42 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:42+01:00" level=debug msg="new websocket client" Dec 05 17:45:42 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket established Dec 05 17:45:42 volumio-aras volumio[1352]: info: go-librespot daemon successfully initialized Dec 05 17:45:45 volumio-aras volumio[1352]: info: Getting Spotify volume Dec 05 17:45:45 volumio-aras volumio[1352]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Dec 05 17:45:45 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetState Dec 05 17:45:45 volumio-aras volumio[1352]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Dec 05 17:45:45 volumio-aras volumio[1352]: info: Initializing connection to go-librespot Websocket Dec 05 17:45:45 volumio-aras go-librespot[5186]: time="2025-12-05T17:45:45+01:00" level=debug msg="new websocket client" Dec 05 17:45:45 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket established Dec 05 17:45:48 volumio-aras volumio[1352]: info: Received OAUTH Data Dec 05 17:45:48 volumio-aras volumio[1352]: info: Executing Spotify Oauth Login Dec 05 17:45:48 volumio-aras volumio[1352]: info: Saving Spotify Refresh Token Dec 05 17:45:48 volumio-aras volumio[1352]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 17:45:48 volumio-aras volumio[1352]: SPOTIFY: BQCT-puCxz71v3LNuCm-8lSMRTeC61W6ZmvhaCndLlfAq_itIqWnHDEnDi6RD_4EUVc5c56Ne39oqe7fdQFezh5fzaKHqOslwNpTcXhTnX4wnE3GxC8prENcD-q9wxcgBknBQy2P-SYk6TSMvojdJq143nSDATFUlY5OnD2P4wSJylo7bZOQCqUBqzBJM3w_B9_0zGAahUTjD9gIgfgH9YUJduhPZG7CKxxNp6HnQlt7arN5mup7vg_B_VDcko-lmiFgbz7rBJGA2QTe0Z7PIUtOBEaSt0GeOh4BqNO-f6U Dec 05 17:45:48 volumio-aras volumio[1352]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 17:45:48 volumio-aras volumio[1352]: info: New Spotify access token = BQCT-puCxz71v3LNuCm-8lSMRTeC61W6ZmvhaCndLlfAq_itIqWnHDEnDi6RD_4EUVc5c56Ne39oqe7fdQFezh5fzaKHqOslwNpTcXhTnX4wnE3GxC8prENcD-q9wxcgBknBQy2P-SYk6TSMvojdJq143nSDATFUlY5OnD2P4wSJylo7bZOQCqUBqzBJM3w_B9_0zGAahUTjD9gIgfgH9YUJduhPZG7CKxxNp6HnQlt7arN5mup7vg_B_VDcko-lmiFgbz7rBJGA2QTe0Z7PIUtOBEaSt0GeOh4BqNO-f6U Dec 05 17:45:48 volumio-aras volumio[1352]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 05 17:45:48 volumio-aras volumio[1352]: info: Getting Spotify volume Dec 05 17:45:48 volumio-aras volumio[1352]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Dec 05 17:45:48 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetState Dec 05 17:45:48 volumio-aras volumio[1352]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Dec 05 17:45:48 volumio-aras volumio[1352]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Dec 05 17:45:48 volumio-aras volumio[1352]: SPOTIFY: User informations: {"country":"PL","display_name":"martinklimatech","email":"martinklimatech@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/martinklimatech"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/martinklimatech","id":"martinklimatech","images":[],"product":"premium","type":"user","uri":"spotify:user:martinklimatech"} Dec 05 17:45:48 volumio-aras volumio[1352]: info: Creating Spotify config file Dec 05 17:45:48 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 17:45:48 volumio-aras volumio[1352]: info: Spotify config file written Dec 05 17:45:48 volumio-aras sudo[5250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 05 17:45:48 volumio-aras sudo[5250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:45:48 volumio-aras systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 05 17:45:48 volumio-aras systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 05 17:45:48 volumio-aras systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:45:48 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket closed Dec 05 17:45:48 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket closed Dec 05 17:45:48 volumio-aras systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:45:48 volumio-aras sudo[5250]: pam_unix(sudo:session): session closed for user root Dec 05 17:45:48 volumio-aras go-librespot[5252]: go-librespot daemon starting... Dec 05 17:45:48 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:48+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 17:45:48 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:48+01:00" level=debug msg="app state loaded" Dec 05 17:45:48 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:48+01:00" level=debug msg="stored credentials not found" Dec 05 17:45:48 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 17:45:48 volumio-aras volumio[1352]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 17:45:48 volumio-aras volumio[1352]: SPOTIFY: BQDmZWUuuQR8LOdG17206ZKiVYM51FnH2NyLLt9aZ7Tf_GOAKYu685rwV84ETuRYNbOyeXNAn6kqNZtF0naXgK1DmhSsDQ-Wpk6udROXF2-ieIUd9ZTFzhVdKnugAANxk4UOt-C7JHx6f_8wbp9aMmRPzws74vIieEZWNTyZYKw4mlQ1bRwMAiWPq4r83cZK8sWysUNuE9YYy-7DGWA4hfo4bFJBDLIMgAHJ0FMiRgbqqiMZMdMrx7KRcn1e0I2-X77boQhak0SCM01LfLuu3E5faNBpTWPTVXC_q4sU9h8 Dec 05 17:45:48 volumio-aras volumio[1352]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 17:45:48 volumio-aras volumio[1352]: info: New Spotify access token = BQDmZWUuuQR8LOdG17206ZKiVYM51FnH2NyLLt9aZ7Tf_GOAKYu685rwV84ETuRYNbOyeXNAn6kqNZtF0naXgK1DmhSsDQ-Wpk6udROXF2-ieIUd9ZTFzhVdKnugAANxk4UOt-C7JHx6f_8wbp9aMmRPzws74vIieEZWNTyZYKw4mlQ1bRwMAiWPq4r83cZK8sWysUNuE9YYy-7DGWA4hfo4bFJBDLIMgAHJ0FMiRgbqqiMZMdMrx7KRcn1e0I2-X77boQhak0SCM01LfLuu3E5faNBpTWPTVXC_q4sU9h8 Dec 05 17:45:48 volumio-aras volumio[1352]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 05 17:45:48 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 05 17:45:48 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:48+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 05 17:45:48 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:48+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 05 17:45:48 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:48+01:00" level=info msg="zeroconf server listening on port 42219" Dec 05 17:45:48 volumio-aras volumio[1352]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 17:45:48 volumio-aras volumio[1352]: SPOTIFY: User informations: {"country":"PL","display_name":"martinklimatech","email":"martinklimatech@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/martinklimatech"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/martinklimatech","id":"martinklimatech","images":[],"product":"premium","type":"user","uri":"spotify:user:martinklimatech"} Dec 05 17:45:48 volumio-aras volumio[1352]: info: Spotify Successfully logged in Dec 05 17:45:48 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 17:45:48 volumio-aras volumio[1352]: info: [1764953148855] CoreMusicLibrary::Adding element Spotify Dec 05 17:45:48 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source Bandcamp Discover Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source YouTube2 Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source YouTube Music Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source 80s80s Radio Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source Controradio Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source RADIO 357 Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source Radio Paradise Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source Volusonic Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source LastFM Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source FM/DAB Radio Dec 05 17:45:48 volumio-aras volumio[1352]: Cannot find translation for source Spotify Dec 05 17:45:49 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 17:45:49 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetState Dec 05 17:45:49 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 17:45:49 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 17:45:49 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 05 17:45:49 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 05 17:45:49 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 05 17:45:49 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 05 17:45:49 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:49+01:00" level=debug msg="obtained new client token: AAAhfottUYr4FoIadiZP+brmc2jEtPyC+J4GDp5ttnjlsM4Tf9gZ9KTRYllh9f7c4fqwfRamXRkJmP+/hjm2zisdbrQ2YJvjWzJg8ZiNwqIX7MwH7BRx5fAI0wKw+yK/UbcAKQeqTnl6Xj4XpyyOrnOdNpdvyRj43kgP5rowjHZPp492NBUaSdCFLtef4bZR5CL/SFDYpekrKTvz9TdkQSx2rvCE283doDpRaoieNIo2vQOloY4R" Dec 05 17:45:49 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:49+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 05 17:45:49 volumio-aras go-librespot[5253]: time="2025-12-05T17:45:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 05 17:45:49 volumio-aras systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 17:45:49 volumio-aras systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 17:45:51 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 17:45:51 volumio-aras volumio[1352]: info: Received Get System Info Dec 05 17:45:51 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 17:45:51 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 17:45:51 volumio-aras volumio[1352]: info: Discovery: Getting this device information Dec 05 17:45:51 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetState Dec 05 17:45:51 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 17:45:51 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 17:45:51 volumio-aras volumio[1352]: info: Received Get System Info Dec 05 17:45:51 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 05 17:45:51 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 05 17:45:51 volumio-aras volumio[1352]: info: Discovery: Getting this device information Dec 05 17:45:51 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetState Dec 05 17:45:51 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 05 17:45:51 volumio-aras volumio[1352]: info: Initializing connection to go-librespot Websocket Dec 05 17:45:51 volumio-aras volumio[1352]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 17:45:51 volumio-aras volumio[1352]: info: go-librespot daemon successfully initialized Dec 05 17:45:52 volumio-aras volumio[1352]: info: CALLMETHOD: music_service spop logout Dec 05 17:45:52 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: spop , logout Dec 05 17:45:52 volumio-aras volumio[1352]: info: Deleting Spotify credentials File Dec 05 17:45:52 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Dec 05 17:45:52 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 17:45:52 volumio-aras volumio[1352]: Cannot find translation for source Bandcamp Discover Dec 05 17:45:52 volumio-aras volumio[1352]: Cannot find translation for source YouTube2 Dec 05 17:45:52 volumio-aras volumio[1352]: Cannot find translation for source YouTube Music Dec 05 17:45:52 volumio-aras volumio[1352]: Cannot find translation for source 80s80s Radio Dec 05 17:45:52 volumio-aras volumio[1352]: Cannot find translation for source Controradio Dec 05 17:45:52 volumio-aras volumio[1352]: Cannot find translation for source RADIO 357 Dec 05 17:45:52 volumio-aras volumio[1352]: Cannot find translation for source Radio Paradise Dec 05 17:45:52 volumio-aras volumio[1352]: Cannot find translation for source Volusonic Dec 05 17:45:52 volumio-aras volumio[1352]: Cannot find translation for source LastFM Dec 05 17:45:52 volumio-aras volumio[1352]: Cannot find translation for source FM/DAB Radio Dec 05 17:45:52 volumio-aras systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 05 17:45:52 volumio-aras systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:45:52 volumio-aras systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:45:52 volumio-aras go-librespot[5262]: go-librespot daemon starting... Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=debug msg="no app state found" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=debug msg="stored credentials not found" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=info msg="generated new device id: deb5cb0c78d2d3780fb14b4cb2a4a064c86e0323" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=info msg="zeroconf server listening on port 39403" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=debug msg="obtained new client token: AAB4kQPQowHEfCAWgvhfGYS2PeUq42vgbutU3W2krcm9AhkhV4+/8i0zNge4G/qEZH/8nD7RhA3jQuqGipsrf7iN3AAcrwqsxJnWOHOwjpmf3LNll29pTAGpGZgK2eoOnJo2IebbTXFgwJCRwJPWtl1xjG3m96PAx/vHz3PpExUHajKdGEF134lcu0TZgJRzPatRS0tSv0preW9Hx2ZSyuCUa6XInujIa7fsB2Hbitc4fd+HKSt8Bag=" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 05 17:45:52 volumio-aras go-librespot[5263]: time="2025-12-05T17:45:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.0.45:52302->34.158.1.133:4070: read: connection reset by peer" Dec 05 17:45:52 volumio-aras systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 17:45:52 volumio-aras systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 17:45:53 volumio-aras volumio[1352]: info: Creating Spotify config file Dec 05 17:45:53 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 17:45:53 volumio-aras volumio[1352]: info: Spotify config file written Dec 05 17:45:53 volumio-aras sudo[5272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 05 17:45:53 volumio-aras sudo[5272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:45:53 volumio-aras systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:45:53 volumio-aras systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:45:53 volumio-aras go-librespot[5274]: go-librespot daemon starting... Dec 05 17:45:53 volumio-aras sudo[5272]: pam_unix(sudo:session): session closed for user root Dec 05 17:45:53 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:53+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 17:45:53 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:53+01:00" level=debug msg="app state loaded" Dec 05 17:45:53 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:53+01:00" level=debug msg="stored credentials not found" Dec 05 17:45:53 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 17:45:53 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:53+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 05 17:45:53 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:53+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 05 17:45:53 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:53+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 05 17:45:53 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:53+01:00" level=info msg="zeroconf server listening on port 45973" Dec 05 17:45:54 volumio-aras volumio[1352]: info: Initializing connection to go-librespot Websocket Dec 05 17:45:54 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:54+01:00" level=debug msg="new websocket client" Dec 05 17:45:54 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket established Dec 05 17:45:54 volumio-aras volumio[1352]: info: Initializing connection to go-librespot Websocket Dec 05 17:45:54 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket established Dec 05 17:45:54 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:54+01:00" level=debug msg="new websocket client" Dec 05 17:45:56 volumio-aras volumio[1352]: info: go-librespot daemon successfully initialized Dec 05 17:45:57 volumio-aras volumio[1352]: info: Getting Spotify volume Dec 05 17:45:57 volumio-aras volumio[1352]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Dec 05 17:45:57 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetState Dec 05 17:45:57 volumio-aras volumio[1352]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Dec 05 17:45:57 volumio-aras volumio[1352]: info: Getting Spotify volume Dec 05 17:45:57 volumio-aras volumio[1352]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Dec 05 17:45:57 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetState Dec 05 17:45:57 volumio-aras volumio[1352]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Dec 05 17:45:59 volumio-aras volumio[1352]: info: Initializing connection to go-librespot Websocket Dec 05 17:45:59 volumio-aras go-librespot[5275]: time="2025-12-05T17:45:59+01:00" level=debug msg="new websocket client" Dec 05 17:45:59 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket established Dec 05 17:45:59 volumio-aras volumio[1352]: info: Received OAUTH Data Dec 05 17:45:59 volumio-aras volumio[1352]: info: Executing Spotify Oauth Login Dec 05 17:45:59 volumio-aras volumio[1352]: info: Saving Spotify Refresh Token Dec 05 17:45:59 volumio-aras volumio[1352]: info: Dec 05 17:45:59 volumio-aras volumio[1352]: ---------------------------- MPD announces system playlist update Dec 05 17:45:59 volumio-aras volumio[1352]: info: Ignoring MPD Status Update Dec 05 17:45:59 volumio-aras volumio[1352]: info: Dec 05 17:45:59 volumio-aras volumio[1352]: ---------------------------- MPD announces state update: player Dec 05 17:45:59 volumio-aras volumio[1352]: info: ControllerMpd::getState Dec 05 17:45:59 volumio-aras volumio[1352]: verbose: ControllerMpd::sendMpdCommand status Dec 05 17:45:59 volumio-aras volumio[1352]: info: ------------------------------ 1ms Dec 05 17:45:59 volumio-aras volumio[1352]: info: sendMpdCommand status took 1 milliseconds Dec 05 17:45:59 volumio-aras volumio[1352]: verbose: ControllerMpd::parseState Dec 05 17:45:59 volumio-aras volumio[1352]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 05 17:45:59 volumio-aras volumio[1352]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 05 17:45:59 volumio-aras volumio[1352]: verbose: ControllerMpd::parseTrackInfo Dec 05 17:45:59 volumio-aras volumio[1352]: info: ControllerMpd::pushState Dec 05 17:45:59 volumio-aras volumio[1352]: info: CoreCommandRouter::servicePushState Dec 05 17:45:59 volumio-aras volumio[1352]: info: CorePlayQueue::getTrack 0 Dec 05 17:45:59 volumio-aras volumio[1352]: verbose: STATE SERVICE {"status":"play","position":0,"seek":725291,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Radio 357 - Najlepszy radiowy adres na świecie!","artist":"Radio 357","album":null,"uri":"http://stream.rcs.revma.com/ye5kghkgcm0uv","trackType":""} Dec 05 17:45:59 volumio-aras volumio[1352]: verbose: CURRENT POSITION 0 Dec 05 17:45:59 volumio-aras volumio[1352]: info: CoreStateMachine::syncState stateService play Dec 05 17:45:59 volumio-aras volumio[1352]: info: CoreStateMachine::syncState currentStatus play Dec 05 17:45:59 volumio-aras volumio[1352]: info: Received an update from plugin. extracting info from payload Dec 05 17:45:59 volumio-aras volumio[1352]: info: CoreStateMachine::pushState Dec 05 17:45:59 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 17:45:59 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioPushState Dec 05 17:45:59 volumio-aras volumio[1352]: info: CoreStateMachine::pushState Dec 05 17:45:59 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioPushState Dec 05 17:45:59 volumio-aras volumio[1352]: info: ------------------------------ 24ms Dec 05 17:45:59 volumio-aras volumio[1352]: info: [LastFM] Split composite title into artist: Radio 357 and title: Najlepszy radiowy adres na świecie! Dec 05 17:45:59 volumio-aras volumio[1352]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Dec 05 17:45:59 volumio-aras volumio[1352]: info: FusionDsp - Volumio is playing Dec 05 17:45:59 volumio-aras volumio[1352]: info: FusionDsp - Volumio is playing Dec 05 17:45:59 volumio-aras volumio[1352]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Dec 05 17:45:59 volumio-aras volumio[1352]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Dec 05 17:45:59 volumio-aras volumio[1352]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 17:45:59 volumio-aras volumio[1352]: SPOTIFY: BQDNVw2-We7KqemKE41llYwGSUyPegI2rTEdhXwFlcpmLogL7-uH2M69ANCww77lAbvYbU7wOYmEo2FcY3iXY7gikiRccKb-iJMMkdrCU8rRvgN0WYoqB3OKdKSXQQP-Y5zU1bGyqg_5Tq9aewK29OX0BOARo9iBX8Lrxwwt16o96o_DN-j8BeUJgQK1ZA1tziOHXfTeGCst7MJuqUFEy22HLl4aIP1En7T9hw-NyIbTxM1IU2nv59wILjSlr3H-WL01mxUY8NAKEAlZ2u-JEUXa0zlswgjpPk7B68qaXik Dec 05 17:45:59 volumio-aras volumio[1352]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 17:45:59 volumio-aras volumio[1352]: info: New Spotify access token = BQDNVw2-We7KqemKE41llYwGSUyPegI2rTEdhXwFlcpmLogL7-uH2M69ANCww77lAbvYbU7wOYmEo2FcY3iXY7gikiRccKb-iJMMkdrCU8rRvgN0WYoqB3OKdKSXQQP-Y5zU1bGyqg_5Tq9aewK29OX0BOARo9iBX8Lrxwwt16o96o_DN-j8BeUJgQK1ZA1tziOHXfTeGCst7MJuqUFEy22HLl4aIP1En7T9hw-NyIbTxM1IU2nv59wILjSlr3H-WL01mxUY8NAKEAlZ2u-JEUXa0zlswgjpPk7B68qaXik Dec 05 17:45:59 volumio-aras volumio[1352]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 05 17:45:59 volumio-aras volumio[1352]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Dec 05 17:45:59 volumio-aras volumio[1352]: SPOTIFY: User informations: {"country":"PL","display_name":"martinklimatech","email":"martinklimatech@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/martinklimatech"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/martinklimatech","id":"martinklimatech","images":[],"product":"premium","type":"user","uri":"spotify:user:martinklimatech"} Dec 05 17:45:59 volumio-aras volumio[1352]: info: Creating Spotify config file Dec 05 17:45:59 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 17:45:59 volumio-aras volumio[1352]: info: Spotify config file written Dec 05 17:45:59 volumio-aras sudo[5330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 05 17:45:59 volumio-aras sudo[5330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 17:45:59 volumio-aras systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 05 17:45:59 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket closed Dec 05 17:45:59 volumio-aras systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 05 17:45:59 volumio-aras systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:45:59 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket closed Dec 05 17:45:59 volumio-aras volumio[1352]: info: Connection to go-librespot Websocket closed Dec 05 17:45:59 volumio-aras systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 17:45:59 volumio-aras go-librespot[5332]: go-librespot daemon starting... Dec 05 17:45:59 volumio-aras sudo[5330]: pam_unix(sudo:session): session closed for user root Dec 05 17:45:59 volumio-aras go-librespot[5333]: time="2025-12-05T17:45:59+01:00" level=info msg="running go-librespot 0.4.0" Dec 05 17:45:59 volumio-aras go-librespot[5333]: time="2025-12-05T17:45:59+01:00" level=debug msg="app state loaded" Dec 05 17:45:59 volumio-aras go-librespot[5333]: time="2025-12-05T17:45:59+01:00" level=debug msg="stored credentials not found" Dec 05 17:45:59 volumio-aras go-librespot[5333]: time="2025-12-05T17:45:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 17:46:00 volumio-aras volumio[1352]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 17:46:00 volumio-aras volumio[1352]: SPOTIFY: BQCDTsGRcBFmM-vrHEzcwJxIunv6TupjcQWxkgnmF10UVKESUIyO1ZN9ZlZzykFh3i57JevrlYQvw3IJ5O4UofsXdln64j5-gSt3ZICvd4k57bPGTMo8XfcSBYuB_l2Q3aPxKgJYlht8a5kFu6DzyQB95DFpucGE46MA00Lq9MOeGdneUp9vUoGOhReoXy8wRUmqXFACKVqtVn-Iic7oUNyHH2h1tR4GA2890E_FS3U-Su6vhFvWJMQnq9ITYzgAQfWiOtlV0pi4FvwSKJTZZ6szhydbLRQtV1WH8goswB8 Dec 05 17:46:00 volumio-aras volumio[1352]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 05 17:46:00 volumio-aras volumio[1352]: info: New Spotify access token = BQCDTsGRcBFmM-vrHEzcwJxIunv6TupjcQWxkgnmF10UVKESUIyO1ZN9ZlZzykFh3i57JevrlYQvw3IJ5O4UofsXdln64j5-gSt3ZICvd4k57bPGTMo8XfcSBYuB_l2Q3aPxKgJYlht8a5kFu6DzyQB95DFpucGE46MA00Lq9MOeGdneUp9vUoGOhReoXy8wRUmqXFACKVqtVn-Iic7oUNyHH2h1tR4GA2890E_FS3U-Su6vhFvWJMQnq9ITYzgAQfWiOtlV0pi4FvwSKJTZZ6szhydbLRQtV1WH8goswB8 Dec 05 17:46:00 volumio-aras volumio[1352]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 05 17:46:00 volumio-aras go-librespot[5333]: time="2025-12-05T17:46:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 05 17:46:00 volumio-aras go-librespot[5333]: time="2025-12-05T17:46:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 05 17:46:00 volumio-aras go-librespot[5333]: time="2025-12-05T17:46:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 05 17:46:00 volumio-aras go-librespot[5333]: time="2025-12-05T17:46:00+01:00" level=info msg="zeroconf server listening on port 39405" Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 05 17:46:00 volumio-aras go-librespot[5333]: time="2025-12-05T17:46:00+01:00" level=debug msg="obtained new client token: AACDXPf5LHwlqX7Kzjv/exVEFrjh/cGydzjPlNmrXFhmzT6DquBbbuC0wJupH6ptwHUfVRuTpbHOv3Z1gevstWLu1204qJlvJ9fT8ikw6mYeTO5e84JM8bGPckjwC9sIL58cBwAW8but+utdVSQVd4ODG3bAbWjvZh6dFH6kkAJA5kkxlLK0To89/MSQwodNbxJpoTK8uVPvCfeTvDWhQqx0chgt6qF2TrYa4S/VRlC5yy8a0C15" Dec 05 17:46:00 volumio-aras go-librespot[5333]: time="2025-12-05T17:46:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 05 17:46:00 volumio-aras volumio[1352]: SPOTIFY: User informations: {"country":"PL","display_name":"martinklimatech","email":"martinklimatech@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/martinklimatech"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/martinklimatech","id":"martinklimatech","images":[],"product":"premium","type":"user","uri":"spotify:user:martinklimatech"} Dec 05 17:46:00 volumio-aras volumio[1352]: info: Spotify Successfully logged in Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 17:46:00 volumio-aras volumio[1352]: info: [1764953160233] CoreMusicLibrary::Adding element Spotify Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source Bandcamp Discover Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source YouTube2 Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source YouTube Music Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source 80s80s Radio Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source Controradio Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source RADIO 357 Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source Radio Paradise Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source Volusonic Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source LastFM Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source FM/DAB Radio Dec 05 17:46:00 volumio-aras volumio[1352]: Cannot find translation for source Spotify Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetState Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 05 17:46:00 volumio-aras volumio[1352]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 05 17:46:00 volumio-aras go-librespot[5333]: time="2025-12-05T17:46:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.0.45:44696->34.158.1.133:4070: read: connection reset by peer" Dec 05 17:46:00 volumio-aras systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 17:46:00 volumio-aras systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 17:46:02 volumio-aras volumio[1352]: info: Getting Spotify volume Dec 05 17:46:02 volumio-aras volumio[1352]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 17:46:02 volumio-aras volumio[1352]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 17:46:02 volumio-aras volumio[1352]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 05 17:46:02 volumio-aras volumio[1352]: errno: -111, Dec 05 17:46:02 volumio-aras volumio[1352]: code: 'ECONNREFUSED', Dec 05 17:46:02 volumio-aras volumio[1352]: syscall: 'connect', Dec 05 17:46:02 volumio-aras volumio[1352]: address: '127.0.0.1', Dec 05 17:46:02 volumio-aras volumio[1352]: port: 9879, Dec 05 17:46:02 volumio-aras volumio[1352]: response: undefined Dec 05 17:46:02 volumio-aras volumio[1352]: } Dec 05 17:46:02 volumio-aras volumio[1352]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 17:46:02 volumio-aras sudo[5354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-05 17:45' Dec 05 17:46:02 volumio-aras sudo[5354]: 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="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025" VOLUMIO_VERSION="4.072" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"