Dec 08 14:05:22 volumio-reception volumio[4411]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Dec 08 14:05:24 volumio-reception volumio[4411]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Dec 08 14:05:24 volumio-reception volumio[4411]: info: Folder /tmp/plugins removed Dec 08 14:05:25 volumio-reception volumio[4411]: info: Check plugin dependencies Dec 08 14:05:25 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 14:05:25 volumio-reception volumio[4411]: info: Checking if plugin already exists Dec 08 14:05:25 volumio-reception volumio[4411]: info: Rename folder Dec 08 14:05:25 volumio-reception volumio[4411]: info: Folder /tmp/downloaded_plugin.zip removed Dec 08 14:05:25 volumio-reception volumio[4411]: info: Move to category Dec 08 14:05:26 volumio-reception volumio[4411]: info: Checking if install.sh is present Dec 08 14:05:26 volumio-reception volumio[4411]: info: Executing install.sh Dec 08 14:05:26 volumio-reception sudo[5475]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh Dec 08 14:05:26 volumio-reception sudo[5475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:05:26 volumio-reception volumio[4411]: info: Installing Go-librespot Dec 08 14:05:26 volumio-reception volumio[4411]: info: Checking old vollibrespot installs Dec 08 14:05:26 volumio-reception systemd[1]: Reloading. Dec 08 14:05:27 volumio-reception volumio[4411]: info: Downloading daemon Dec 08 14:05:28 volumio-reception volumio[4411]: info: Creating directories Dec 08 14:05:28 volumio-reception volumio[4411]: info: Creating data directory Dec 08 14:05:28 volumio-reception volumio[4411]: info: Creating Start Script Dec 08 14:05:28 volumio-reception systemd[1]: Reloading. Dec 08 14:05:29 volumio-reception sudo[5475]: pam_unix(sudo:session): session closed for user root Dec 08 14:05:29 volumio-reception volumio[4411]: Plugin install end detected on script Dec 08 14:05:29 volumio-reception volumio[4411]: info: Install script completed Dec 08 14:05:29 volumio-reception volumio[4411]: info: Adding reference to registry Dec 08 14:05:29 volumio-reception volumio[4411]: info: Done installing plugin. Dec 08 14:05:29 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 14:05:29 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 08 14:05:29 volumio-reception volumio[4411]: info: Folder /tmp/plugins removed Dec 08 14:05:29 volumio-reception volumio[4411]: info: Folder /tmp/downloaded_plugin.zip removed Dec 08 14:05:29 volumio-reception volumio[4411]: info: Folder /data/temp removed Dec 08 14:05:32 volumio-reception volumio[4411]: info: Enabling plugin spop Dec 08 14:05:32 volumio-reception volumio[4411]: info: Loading plugin "spop"... Dec 08 14:05:33 volumio-reception volumio[4411]: info: PLUGIN START: spop Dec 08 14:05:33 volumio-reception volumio[4411]: info: Creating Spotify config file Dec 08 14:05:33 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 14:05:33 volumio-reception volumio[4411]: info: Done. Dec 08 14:05:33 volumio-reception volumio[4411]: info: Spotify config file written Dec 08 14:05:33 volumio-reception volumio[4411]: info: No need to fix Spotify hosts Dec 08 14:05:33 volumio-reception sudo[5534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 08 14:05:33 volumio-reception sudo[5534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:05:33 volumio-reception systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 08 14:05:33 volumio-reception systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 08 14:05:33 volumio-reception systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:05:33 volumio-reception go-librespot[5536]: go-librespot daemon starting... Dec 08 14:05:33 volumio-reception sudo[5534]: pam_unix(sudo:session): session closed for user root Dec 08 14:05:33 volumio-reception go-librespot[5537]: time="2025-12-08T14:05:33+01:00" level=info msg="running go-librespot 0.4.0" Dec 08 14:05:33 volumio-reception go-librespot[5537]: time="2025-12-08T14:05:33+01:00" level=debug msg="no app state found" Dec 08 14:05:33 volumio-reception go-librespot[5537]: time="2025-12-08T14:05:33+01:00" level=debug msg="stored credentials not found" Dec 08 14:05:33 volumio-reception go-librespot[5537]: time="2025-12-08T14:05:33+01:00" level=info msg="generated new device id: fe28c878f87ba5cd8a7f882401992625b8303f48" Dec 08 14:05:33 volumio-reception go-librespot[5537]: time="2025-12-08T14:05:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 14:05:33 volumio-reception go-librespot[5537]: time="2025-12-08T14:05:33+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-gew1.spotify.com:80]" Dec 08 14:05:33 volumio-reception go-librespot[5537]: time="2025-12-08T14:05:33+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 08 14:05:33 volumio-reception go-librespot[5537]: time="2025-12-08T14:05:33+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 08 14:05:33 volumio-reception go-librespot[5537]: time="2025-12-08T14:05:33+01:00" level=info msg="zeroconf server listening on port 33831" Dec 08 14:05:36 volumio-reception volumio[4411]: info: go-librespot daemon successfully initialized Dec 08 14:05:39 volumio-reception volumio[4411]: info: Initializing connection to go-librespot Websocket Dec 08 14:05:39 volumio-reception go-librespot[5537]: time="2025-12-08T14:05:39+01:00" level=debug msg="new websocket client" Dec 08 14:05:39 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket established Dec 08 14:05:40 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:05:42 volumio-reception volumio[4411]: info: Getting Spotify volume Dec 08 14:05:42 volumio-reception volumio[4411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 08 14:05:42 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:05:42 volumio-reception volumio[4411]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Dec 08 14:05:42 volumio-reception volumio[4411]: SPOTIFY: SPOTIFY VOLUME undefined Dec 08 14:05:42 volumio-reception volumio[4411]: SPOTIFY: VOLUMIO VOLUME 46 Dec 08 14:05:42 volumio-reception volumio[4411]: info: Aligning Spotify Volume to Volumio Volume Dec 08 14:05:42 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:05:42 volumio-reception volumio[4411]: info: Setting Spotify Volume from Volumio: 46 Dec 08 14:05:43 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 14:05:43 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 08 14:05:44 volumio-reception volumio[4411]: SPOTIFY: SETTING SPOTIFY VOLUME 46 Dec 08 14:05:44 volumio-reception volumio[4411]: info: Sending Spotify command with payload to local API: /player/volume Dec 08 14:05:47 volumio-reception volumio[4411]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 14:05:55 volumio-reception volumio[4411]: info: Received OAUTH Data Dec 08 14:05:55 volumio-reception volumio[4411]: info: Executing Spotify Oauth Login Dec 08 14:05:55 volumio-reception volumio[4411]: info: Saving Spotify Refresh Token Dec 08 14:05:55 volumio-reception volumio[4411]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 08 14:05:55 volumio-reception volumio[4411]: SPOTIFY: BQDczLwOBU7UQBZ7_2qHxsAnJGUGAQCNMUfl3ZL5RIonKGfZh7je39Zf-T23Qp56bIWVdqC5GmiLDS6Pud4Rk1Iow2Ll_-TFKHnHVMKOC2q4FAgN-bmFuFJ_HcKO1bybYpVD6nEHx8hocU7dKH7dDrQvPwKbJwbSKyDUIXl8hwIu8WmYJVMW4f7ocGeqwGHWFGMbnSkO_76uo6WXTbMyAC7zftHPq8c94daJUJM9-bx_rNhCrhxW4VH5MSUarf_gvx6lyHFAxg9cnDG8XX8WJ-KF1flmhIZoSGlaNlp3hKCbMoCKKy8vu6QZeYux Dec 08 14:05:55 volumio-reception volumio[4411]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 08 14:05:55 volumio-reception volumio[4411]: info: New Spotify access token = BQDczLwOBU7UQBZ7_2qHxsAnJGUGAQCNMUfl3ZL5RIonKGfZh7je39Zf-T23Qp56bIWVdqC5GmiLDS6Pud4Rk1Iow2Ll_-TFKHnHVMKOC2q4FAgN-bmFuFJ_HcKO1bybYpVD6nEHx8hocU7dKH7dDrQvPwKbJwbSKyDUIXl8hwIu8WmYJVMW4f7ocGeqwGHWFGMbnSkO_76uo6WXTbMyAC7zftHPq8c94daJUJM9-bx_rNhCrhxW4VH5MSUarf_gvx6lyHFAxg9cnDG8XX8WJ-KF1flmhIZoSGlaNlp3hKCbMoCKKy8vu6QZeYux Dec 08 14:05:55 volumio-reception volumio[4411]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 08 14:05:55 volumio-reception volumio[4411]: SPOTIFY: User informations: {"country":"NL","display_name":"The Elephant Hostel","email":"info@theelephanthostel.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31deawchxvujby3kj4oi4x74faay"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31deawchxvujby3kj4oi4x74faay","id":"31deawchxvujby3kj4oi4x74faay","images":[],"product":"premium","type":"user","uri":"spotify:user:31deawchxvujby3kj4oi4x74faay"} Dec 08 14:05:55 volumio-reception volumio[4411]: info: Creating Spotify config file Dec 08 14:05:55 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 14:05:55 volumio-reception volumio[4411]: info: Spotify config file written Dec 08 14:05:55 volumio-reception sudo[5592]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 08 14:05:55 volumio-reception sudo[5592]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:05:55 volumio-reception systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 08 14:05:55 volumio-reception systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 08 14:05:55 volumio-reception systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:05:55 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket closed Dec 08 14:05:55 volumio-reception systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:05:55 volumio-reception go-librespot[5594]: go-librespot daemon starting... Dec 08 14:05:55 volumio-reception sudo[5592]: pam_unix(sudo:session): session closed for user root Dec 08 14:05:55 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:55+01:00" level=info msg="running go-librespot 0.4.0" Dec 08 14:05:55 volumio-reception volumio[4411]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 08 14:05:55 volumio-reception volumio[4411]: SPOTIFY: BQA1XaELJQgLGu6HgS1_Zc8qWuAGiBozqFnqX2F5EZEACpBASHtkBxFfznwEWNdx3MYZRV9YLY4h8hLTdF82ey8F_VzjyqXZgsuy8cJfpUOR4NpQOyOCTbZlgRDbprUA2-Ub2jol7b-8TLr687XVxnok0Zunq8h9yM2WiEfseFQWO72pynCF2VaJHWtU-TFceK6gbza1wtndamdf8H7RPqSqpNNZKPsmnA3acQam29e-BuAZQ8dtX5RKc2S1NsALzInPa-ExAEQr7Pt_RsW73JVj24pbv6Vgn5I1vEzAFaVa0V2caRxJBrKFKbfX Dec 08 14:05:55 volumio-reception volumio[4411]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 08 14:05:55 volumio-reception volumio[4411]: info: New Spotify access token = BQA1XaELJQgLGu6HgS1_Zc8qWuAGiBozqFnqX2F5EZEACpBASHtkBxFfznwEWNdx3MYZRV9YLY4h8hLTdF82ey8F_VzjyqXZgsuy8cJfpUOR4NpQOyOCTbZlgRDbprUA2-Ub2jol7b-8TLr687XVxnok0Zunq8h9yM2WiEfseFQWO72pynCF2VaJHWtU-TFceK6gbza1wtndamdf8H7RPqSqpNNZKPsmnA3acQam29e-BuAZQ8dtX5RKc2S1NsALzInPa-ExAEQr7Pt_RsW73JVj24pbv6Vgn5I1vEzAFaVa0V2caRxJBrKFKbfX Dec 08 14:05:55 volumio-reception volumio[4411]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 08 14:05:55 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:55+01:00" level=debug msg="app state loaded" Dec 08 14:05:55 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:55+01:00" level=debug msg="stored credentials not found" Dec 08 14:05:55 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+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 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+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 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+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 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=info msg="zeroconf server listening on port 38457" Dec 08 14:05:56 volumio-reception volumio[4411]: SPOTIFY: User informations: {"country":"NL","display_name":"The Elephant Hostel","email":"info@theelephanthostel.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31deawchxvujby3kj4oi4x74faay"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31deawchxvujby3kj4oi4x74faay","id":"31deawchxvujby3kj4oi4x74faay","images":[],"product":"premium","type":"user","uri":"spotify:user:31deawchxvujby3kj4oi4x74faay"} Dec 08 14:05:56 volumio-reception volumio[4411]: info: Spotify Successfully logged in Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 08 14:05:56 volumio-reception volumio[4411]: info: [1765199156062] CoreMusicLibrary::Adding element Spotify Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 14:05:56 volumio-reception volumio[4411]: Cannot find translation for source Spotify Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="obtained new client token: AACM9DYK5tfqPLZzKvSCfgv/e3My5DllKbbndOXhywKXBDBuvquJ3OAIZb42hAtvFnTiExRCKrllNx7VLQPkyUQkQp10SEf/mspaEcUpLEh0og7I2nsKf4c1sF+Xl1kK7PyzwCSbX8gQh2epAFYZGUOW0WxFzNgRuF0JyQReFWsXHR+92LdQMz1xlOmzNwRvuUB7ieaRnn33ORLJ2XHH+P4TA91E1aelL5ssJC3YWTlLqE3n+Lj9oAU=" Dec 08 14:05:56 volumio-reception sudo[5605]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 08 14:05:56 volumio-reception sudo[5603]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 08 14:05:56 volumio-reception sudo[5605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:05:56 volumio-reception sudo[5603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:05:56 volumio-reception sudo[5605]: pam_unix(sudo:session): session closed for user root Dec 08 14:05:56 volumio-reception sudo[5603]: pam_unix(sudo:session): session closed for user root Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="completed keyexchange" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="completed challenge" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=info msg="authenticated AP" username="31************************ay" Dec 08 14:05:56 volumio-reception volumio[4411]: verbose: New Socket.io Connection to 192.168.178.161 from 192.168.178.204 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=info msg="authenticated Login5" username="31************************ay" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="stored credentials" username="31************************ay" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="initializing zeroconf session" username="31************************ay" Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="dealer connection opened" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=trace msg="starting accesspoint recv loop" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=trace msg="starting dealer recv loop" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=trace msg="received accesspoint ping" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="received connection id: YTAwOTI3YjItMTE1...RDUxMEZEQzgzNw==" Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=trace msg="received accesspoint pong ack" Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 08 14:05:56 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:56+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetVisibleSources Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 08 14:05:56 volumio-reception volumio[4411]: info: Received Get System Info Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 14:05:56 volumio-reception volumio[4411]: info: Discovery: Getting this device information Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:05:56 volumio-reception volumio[4411]: info: Listing playlists Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 08 14:05:56 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 08 14:05:58 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 14:05:58 volumio-reception volumio[4411]: info: Received Get System Info Dec 08 14:05:58 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 14:05:58 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 14:05:58 volumio-reception volumio[4411]: info: Discovery: Getting this device information Dec 08 14:05:58 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:05:58 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 14:05:58 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 08 14:05:58 volumio-reception volumio[4411]: info: Initializing connection to go-librespot Websocket Dec 08 14:05:58 volumio-reception go-librespot[5595]: time="2025-12-08T14:05:58+01:00" level=debug msg="new websocket client" Dec 08 14:05:58 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket established Dec 08 14:05:58 volumio-reception volumio[4411]: info: go-librespot daemon successfully initialized Dec 08 14:05:59 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 14:05:59 volumio-reception volumio[4411]: info: Received Get System Info Dec 08 14:05:59 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 14:05:59 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 14:05:59 volumio-reception volumio[4411]: info: Discovery: Getting this device information Dec 08 14:05:59 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:05:59 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 14:06:01 volumio-reception volumio[4411]: info: Getting Spotify volume Dec 08 14:06:01 volumio-reception volumio[4411]: info: Spotify volume: 100 Dec 08 14:06:01 volumio-reception volumio[4411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 08 14:06:01 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:06:01 volumio-reception volumio[4411]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Dec 08 14:06:01 volumio-reception volumio[4411]: SPOTIFY: SPOTIFY VOLUME 100 Dec 08 14:06:01 volumio-reception volumio[4411]: SPOTIFY: VOLUMIO VOLUME 46 Dec 08 14:06:01 volumio-reception volumio[4411]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 08 14:06:01 volumio-reception volumio[4411]: info: Setting Spotify Volume from Volumio: 46 Dec 08 14:06:01 volumio-reception volumio[4411]: info: Initializing connection to go-librespot Websocket Dec 08 14:06:01 volumio-reception go-librespot[5595]: time="2025-12-08T14:06:01+01:00" level=debug msg="new websocket client" Dec 08 14:06:01 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket established Dec 08 14:06:03 volumio-reception volumio[4411]: SPOTIFY: SETTING SPOTIFY VOLUME 46 Dec 08 14:06:03 volumio-reception volumio[4411]: info: Sending Spotify command with payload to local API: /player/volume Dec 08 14:06:03 volumio-reception go-librespot[5595]: time="2025-12-08T14:06:03+01:00" level=debug msg="update volume requested to 30146/65535" Dec 08 14:06:03 volumio-reception go-librespot[5595]: time="2025-12-08T14:06:03+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 08 14:06:03 volumio-reception go-librespot[5595]: time="2025-12-08T14:06:03+01:00" level=trace msg="emitting websocket event: volume" Dec 08 14:06:03 volumio-reception volumio[4411]: SPOTIFY: received: {"type":"volume","data":{"value":46,"max":100}} Dec 08 14:06:03 volumio-reception volumio[4411]: SPOTIFY: RECEIVED SPOTIFY VOLUME 46 Dec 08 14:06:03 volumio-reception volumio[4411]: SPOTIFY: received: {"type":"volume","data":{"value":46,"max":100}} Dec 08 14:06:03 volumio-reception volumio[4411]: SPOTIFY: RECEIVED SPOTIFY VOLUME 46 Dec 08 14:06:04 volumio-reception volumio[4411]: info: Getting Spotify volume Dec 08 14:06:04 volumio-reception volumio[4411]: info: Spotify volume: 46 Dec 08 14:06:04 volumio-reception volumio[4411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 08 14:06:04 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:06:04 volumio-reception volumio[4411]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Dec 08 14:06:05 volumio-reception volumio[4411]: info: CALLMETHOD: music_service spop logout Dec 08 14:06:05 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: spop , logout Dec 08 14:06:05 volumio-reception volumio[4411]: info: Deleting Spotify credentials File Dec 08 14:06:05 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Dec 08 14:06:05 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 14:06:06 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 08 14:06:06 volumio-reception volumio[4411]: info: Creating Spotify config file Dec 08 14:06:06 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 14:06:06 volumio-reception volumio[4411]: info: Spotify config file written Dec 08 14:06:06 volumio-reception sudo[5629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 08 14:06:06 volumio-reception sudo[5629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:06:06 volumio-reception systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 08 14:06:06 volumio-reception systemd[1]: go-librespot-daemon.service: Killing process 5599 (go-librespot) with signal SIGKILL. Dec 08 14:06:06 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket closed Dec 08 14:06:06 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket closed Dec 08 14:06:06 volumio-reception systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 08 14:06:06 volumio-reception systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:06:06 volumio-reception systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:06:06 volumio-reception go-librespot[5631]: go-librespot daemon starting... Dec 08 14:06:06 volumio-reception sudo[5629]: pam_unix(sudo:session): session closed for user root Dec 08 14:06:06 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:06+01:00" level=info msg="running go-librespot 0.4.0" Dec 08 14:06:06 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:06+01:00" level=debug msg="no app state found" Dec 08 14:06:06 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:06+01:00" level=debug msg="stored credentials not found" Dec 08 14:06:06 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:06+01:00" level=info msg="generated new device id: 01161f75e3b26e3d8e7f841746f6703bd10aaf53" Dec 08 14:06:06 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 14:06:06 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:06+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 08 14:06:06 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:06+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 08 14:06:06 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:06+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 08 14:06:06 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:06+01:00" level=info msg="zeroconf server listening on port 37079" Dec 08 14:06:09 volumio-reception volumio[4411]: info: Initializing connection to go-librespot Websocket Dec 08 14:06:09 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:09+01:00" level=debug msg="new websocket client" Dec 08 14:06:09 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket established Dec 08 14:06:09 volumio-reception volumio[4411]: info: go-librespot daemon successfully initialized Dec 08 14:06:12 volumio-reception volumio[4411]: info: Getting Spotify volume Dec 08 14:06:12 volumio-reception volumio[4411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 08 14:06:12 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:06:12 volumio-reception volumio[4411]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Dec 08 14:06:12 volumio-reception volumio[4411]: info: Initializing connection to go-librespot Websocket Dec 08 14:06:12 volumio-reception go-librespot[5632]: time="2025-12-08T14:06:12+01:00" level=debug msg="new websocket client" Dec 08 14:06:12 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket established Dec 08 14:06:14 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 08 14:06:14 volumio-reception volumio[4411]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 08 14:06:14 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 08 14:06:14 volumio-reception volumio[4411]: info: Received Get System Version Dec 08 14:06:14 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 14:06:14 volumio-reception volumio[4411]: info: Received Get System Info Dec 08 14:06:14 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 14:06:14 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 14:06:14 volumio-reception volumio[4411]: info: Discovery: Getting this device information Dec 08 14:06:14 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:06:14 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 14:06:15 volumio-reception volumio[4411]: info: Getting Spotify volume Dec 08 14:06:15 volumio-reception volumio[4411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 08 14:06:15 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:06:15 volumio-reception volumio[4411]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Dec 08 14:06:17 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 14:06:17 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 08 14:06:20 volumio-reception volumio[4411]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 14:06:41 volumio-reception volumio[4411]: info: Received OAUTH Data Dec 08 14:06:41 volumio-reception volumio[4411]: info: Executing Spotify Oauth Login Dec 08 14:06:41 volumio-reception volumio[4411]: info: Saving Spotify Refresh Token Dec 08 14:06:41 volumio-reception volumio[4411]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 08 14:06:41 volumio-reception volumio[4411]: SPOTIFY: BQBXlFAJoyLIcnxDVGNJU_ZOzdZb8TY-17merENHvZAmfal7nCutrMotGqp8nobVaHjP_GkQN79n1oyhwYGLY3tNIRW8ErhiWuk6Nr_RGFfdc1IgXP5q9jpRn04yQ2SOsTgsd02sT7wZ8OOTR8RAlUZhN7YQaPCmWGnLEIdCykKQ8iY4i3AL2cclZ3PWsQqp7a9isDqsRVhA_yak8ap0WVFigb7wF_qL1ECA-HSNZkmzpvGYJK6-Zlg1qcF-u2yZU5MmOZ82d6nQjVoEuwUTozMRtdHZm9ZctZQ2ufmN-GPZP069s1Xr1DYibAyl Dec 08 14:06:41 volumio-reception volumio[4411]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 08 14:06:41 volumio-reception volumio[4411]: info: New Spotify access token = BQBXlFAJoyLIcnxDVGNJU_ZOzdZb8TY-17merENHvZAmfal7nCutrMotGqp8nobVaHjP_GkQN79n1oyhwYGLY3tNIRW8ErhiWuk6Nr_RGFfdc1IgXP5q9jpRn04yQ2SOsTgsd02sT7wZ8OOTR8RAlUZhN7YQaPCmWGnLEIdCykKQ8iY4i3AL2cclZ3PWsQqp7a9isDqsRVhA_yak8ap0WVFigb7wF_qL1ECA-HSNZkmzpvGYJK6-Zlg1qcF-u2yZU5MmOZ82d6nQjVoEuwUTozMRtdHZm9ZctZQ2ufmN-GPZP069s1Xr1DYibAyl Dec 08 14:06:41 volumio-reception volumio[4411]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 08 14:06:41 volumio-reception sudo[5692]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 08 14:06:41 volumio-reception sudo[5692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:06:41 volumio-reception sudo[5692]: pam_unix(sudo:session): session closed for user root Dec 08 14:06:41 volumio-reception sudo[5694]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 08 14:06:41 volumio-reception volumio[4411]: SPOTIFY: User informations: {"country":"NL","display_name":"The Elephant Hostel","email":"info@theelephanthostel.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31deawchxvujby3kj4oi4x74faay"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31deawchxvujby3kj4oi4x74faay","id":"31deawchxvujby3kj4oi4x74faay","images":[],"product":"premium","type":"user","uri":"spotify:user:31deawchxvujby3kj4oi4x74faay"} Dec 08 14:06:41 volumio-reception volumio[4411]: info: Creating Spotify config file Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 14:06:41 volumio-reception sudo[5694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:06:41 volumio-reception sudo[5694]: pam_unix(sudo:session): session closed for user root Dec 08 14:06:41 volumio-reception volumio[4411]: info: Spotify config file written Dec 08 14:06:41 volumio-reception sudo[5698]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 08 14:06:41 volumio-reception sudo[5698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:06:41 volumio-reception volumio[4411]: verbose: New Socket.io Connection to 192.168.178.161 from 192.168.178.175 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 08 14:06:41 volumio-reception systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 08 14:06:41 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket closed Dec 08 14:06:41 volumio-reception systemd[1]: go-librespot-daemon.service: Killing process 5638 (go-librespot) with signal SIGKILL. Dec 08 14:06:41 volumio-reception systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 08 14:06:41 volumio-reception systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:06:41 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket closed Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 08 14:06:41 volumio-reception systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:06:41 volumio-reception go-librespot[5700]: go-librespot daemon starting... Dec 08 14:06:41 volumio-reception volumio[4411]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 08 14:06:41 volumio-reception volumio[4411]: SPOTIFY: BQA0ZYqgYHQWlefaTTG-em8M9XYlj2lABsxbE5UG-BsPnffn8uk56RUPQK48kiRje75hyvAMOmGSMTtIFz7Syp04ghxU9w0kR9q2GZ50A4Tgz4QLqUidnk7oL72Cjh_oCKuzxTekmXQ5G6gZVLMOtHU8lTqyorMtRmT4SZIam0wGTgf9cLv5Yf3d5_pFETyqx55eFjkOkzdg9Y78PiRdf8WlS2IWER29LBhpf1hxIDB_PeGIP0Lx87LwUZnZtgLREtb5U06ssLJr3sgY-hyckFaqcxMQIWEkDtyhqTfE8TXeXH5wX1zuKBqL5A3i Dec 08 14:06:41 volumio-reception volumio[4411]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 08 14:06:41 volumio-reception volumio[4411]: info: New Spotify access token = BQA0ZYqgYHQWlefaTTG-em8M9XYlj2lABsxbE5UG-BsPnffn8uk56RUPQK48kiRje75hyvAMOmGSMTtIFz7Syp04ghxU9w0kR9q2GZ50A4Tgz4QLqUidnk7oL72Cjh_oCKuzxTekmXQ5G6gZVLMOtHU8lTqyorMtRmT4SZIam0wGTgf9cLv5Yf3d5_pFETyqx55eFjkOkzdg9Y78PiRdf8WlS2IWER29LBhpf1hxIDB_PeGIP0Lx87LwUZnZtgLREtb5U06ssLJr3sgY-hyckFaqcxMQIWEkDtyhqTfE8TXeXH5wX1zuKBqL5A3i Dec 08 14:06:41 volumio-reception volumio[4411]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 08 14:06:41 volumio-reception sudo[5698]: pam_unix(sudo:session): session closed for user root Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetVisibleSources Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 08 14:06:41 volumio-reception volumio[4411]: info: Received Get System Info Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 14:06:41 volumio-reception volumio[4411]: info: Discovery: Getting this device information Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:06:41 volumio-reception volumio[4411]: info: Listing playlists Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+01:00" level=info msg="running go-librespot 0.4.0" Dec 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+01:00" level=debug msg="app state loaded" Dec 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+01:00" level=debug msg="stored credentials not found" Dec 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 08 14:06:41 volumio-reception volumio[4411]: SPOTIFY: User informations: {"country":"NL","display_name":"The Elephant Hostel","email":"info@theelephanthostel.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31deawchxvujby3kj4oi4x74faay"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31deawchxvujby3kj4oi4x74faay","id":"31deawchxvujby3kj4oi4x74faay","images":[],"product":"premium","type":"user","uri":"spotify:user:31deawchxvujby3kj4oi4x74faay"} Dec 08 14:06:41 volumio-reception volumio[4411]: info: Spotify Successfully logged in Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 08 14:06:41 volumio-reception volumio[4411]: info: [1765199201529] CoreMusicLibrary::Adding element Spotify Dec 08 14:06:41 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 14:06:41 volumio-reception volumio[4411]: Cannot find translation for source Spotify Dec 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+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 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+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 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+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 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+01:00" level=info msg="zeroconf server listening on port 33307" Dec 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+01:00" level=debug msg="obtained new client token: AAAXY57biul4uVc3bPWTRoHsTedxh3Wl7whL/ucxEG6eQ9C7/CqJ4mxxiAxAj0fl5yguRKadY6x5YDTKBZgZ0jzw3+kXHwZoDhAUsvWAgidRH8GYbOz+xQwOnjBmo4llDwHfOf2fqNIgHr+S63obY1FtDF6u1Q1ca7w8KizoUChr2IZ1odEMDn7ajYTuTUVp9OYYDJ2AA9WTVlp1YRvHZNllTRkxKQotGjEejXoPxFdZlLgNZi29gIDxoA==" Dec 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 08 14:06:41 volumio-reception go-librespot[5701]: time="2025-12-08T14:06:41+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.178.161:53260->34.158.1.133:4070: read: connection reset by peer" Dec 08 14:06:41 volumio-reception systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 14:06:41 volumio-reception systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 14:06:42 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 08 14:06:43 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 14:06:43 volumio-reception volumio[4411]: info: Received Get System Info Dec 08 14:06:43 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 14:06:43 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 14:06:43 volumio-reception volumio[4411]: info: Discovery: Getting this device information Dec 08 14:06:43 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:06:43 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 14:06:43 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 08 14:06:43 volumio-reception volumio[4411]: info: Received Get System Info Dec 08 14:06:43 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 14:06:43 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 14:06:43 volumio-reception volumio[4411]: info: Discovery: Getting this device information Dec 08 14:06:43 volumio-reception volumio[4411]: info: CoreCommandRouter::volumioGetState Dec 08 14:06:43 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 14:06:44 volumio-reception volumio[4411]: info: Initializing connection to go-librespot Websocket Dec 08 14:06:44 volumio-reception volumio[4411]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 14:06:44 volumio-reception volumio[4411]: info: go-librespot daemon successfully initialized Dec 08 14:06:44 volumio-reception systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 08 14:06:44 volumio-reception systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:06:44 volumio-reception systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:06:44 volumio-reception go-librespot[5712]: go-librespot daemon starting... Dec 08 14:06:44 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:44+01:00" level=info msg="running go-librespot 0.4.0" Dec 08 14:06:44 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:44+01:00" level=debug msg="app state loaded" Dec 08 14:06:44 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:44+01:00" level=debug msg="stored credentials not found" Dec 08 14:06:44 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+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-gew1.spotify.com:80]" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=info msg="zeroconf server listening on port 44979" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="obtained new client token: AABuE6DkXdoocXOHoTK7+9Ps2GuBNTdG5hWFpF+G0VN3dOgbCuGwgXTAfakUNu7pJxv0BAeD/Kt9OK0Nf51I6RU/w1Oyj+Vunf5fDb4hkXCUOC50DPqVxcS87SvdnU9vrtVDISoCGZNfajMYnOl1o2IsncFwqshIjoRyFhyyP6YznjKH4XfyO7YKB4ZwDc44t9T6AfV7L9yS+4fEHumncrovIUDnvt6BnKjf94DXTvT+prLqDmqHiqg=" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="completed keyexchange" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="completed challenge" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=info msg="authenticated AP" username="31************************ay" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=info msg="authenticated Login5" username="31************************ay" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="stored credentials" username="31************************ay" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="initializing zeroconf session" username="31************************ay" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="dealer connection opened" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=trace msg="starting accesspoint recv loop" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=trace msg="starting dealer recv loop" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=trace msg="received accesspoint ping" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="received connection id: ODBlYzEwNGItMTFi...NjExMDE0NzNGQQ==" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=trace msg="received accesspoint pong ack" Dec 08 14:06:45 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:45+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 08 14:06:47 volumio-reception volumio[4411]: info: Initializing connection to go-librespot Websocket Dec 08 14:06:47 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:47+01:00" level=debug msg="new websocket client" Dec 08 14:06:47 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket established Dec 08 14:06:47 volumio-reception volumio[4411]: info: Initializing connection to go-librespot Websocket Dec 08 14:06:47 volumio-reception go-librespot[5714]: time="2025-12-08T14:06:47+01:00" level=debug msg="new websocket client" Dec 08 14:06:47 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket established Dec 08 14:06:48 volumio-reception volumio[4411]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 08 14:06:48 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 08 14:06:48 volumio-reception volumio[4411]: info: Creating Spotify config file Dec 08 14:06:48 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 14:06:48 volumio-reception volumio[4411]: info: Spotify config file written Dec 08 14:06:48 volumio-reception sudo[5736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 08 14:06:48 volumio-reception sudo[5736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:06:48 volumio-reception systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 08 14:06:48 volumio-reception systemd[1]: go-librespot-daemon.service: Killing process 5720 (go-librespot) with signal SIGKILL. Dec 08 14:06:48 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket closed Dec 08 14:06:48 volumio-reception volumio[4411]: info: Connection to go-librespot Websocket closed Dec 08 14:06:48 volumio-reception systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 08 14:06:48 volumio-reception systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:06:48 volumio-reception systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:06:48 volumio-reception go-librespot[5738]: go-librespot daemon starting... Dec 08 14:06:48 volumio-reception sudo[5736]: pam_unix(sudo:session): session closed for user root Dec 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:48+01:00" level=info msg="running go-librespot 0.4.0" Dec 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:48+01:00" level=debug msg="app state loaded" Dec 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06: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 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06: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 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06: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 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:48+01:00" level=info msg="zeroconf server listening on port 34497" Dec 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:48+01:00" level=debug msg="obtained new client token: AAAnevl+pbvjJnEUjmZpZ2RuXWxl6SsYFEqbHmB/HZqOUNz864ZeJ5OPn4RDjdavdZLSVhmuI4Ju4v4bk1f3kcxLrm2gB6CWCm8RRgo6l11566xUapNMYf7cI1eE3h8IySQcUNTeGPmt4HtMIvB8UckVgi/JgX1dLVJCQ6wEkLTqvksfnrvEhX0mm7ZvRXm4EHm3rJcy6oCqNHM+x1SvlfzGDssCPc/3hjertuD/goqM0x/fG6nE3roGcw==" Dec 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:48+01:00" level=debug msg="completed keyexchange" Dec 08 14:06:48 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:48+01:00" level=debug msg="completed challenge" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=info msg="authenticated AP" username="31************************ay" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=info msg="authenticated Login5" username="31************************ay" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=debug msg="initializing zeroconf session" username="31************************ay" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=debug msg="dealer connection opened" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=trace msg="starting accesspoint recv loop" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=trace msg="starting dealer recv loop" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=trace msg="received accesspoint ping" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=debug msg="received connection id: ODZhODY0MGUtOGM2...QUEzMTE4QjUyQQ==" Dec 08 14:06:49 volumio-reception go-librespot[5739]: time="2025-12-08T14:06:49+01:00" level=trace msg="received accesspoint pong ack" Dec 08 14:06:49 volumio-reception volumio[4411]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 08 14:06:49 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 08 14:06:49 volumio-reception volumio[4411]: info: Creating Spotify config file Dec 08 14:06:49 volumio-reception volumio[4411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 14:06:49 volumio-reception volumio[4411]: info: Spotify config file written Dec 08 14:06:49 volumio-reception sudo[5749]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 08 14:06:49 volumio-reception sudo[5749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 14:06:49 volumio-reception systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 08 14:06:49 volumio-reception systemd[1]: go-librespot-daemon.service: Killing process 5742 (go-librespot) with signal SIGKILL. Dec 08 14:06:49 volumio-reception systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 08 14:06:49 volumio-reception systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:06:49 volumio-reception systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 08 14:06:49 volumio-reception go-librespot[5751]: go-librespot daemon starting... Dec 08 14:06:49 volumio-reception sudo[5749]: pam_unix(sudo:session): session closed for user root Dec 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+01:00" level=info msg="running go-librespot 0.4.0" Dec 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+01:00" level=debug msg="app state loaded" Dec 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+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 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+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 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+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 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+01:00" level=info msg="zeroconf server listening on port 40261" Dec 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+01:00" level=debug msg="obtained new client token: AAASsgCLbfztvU+KpGP9wg9Q2cuTA1ytr3+Gc0Dcxm/jhnB3ASjpsEZxZrM6dVfsibqlknGTeFLwqX4TzYEOlWaDA9JuIxHMylDbV2oY5NT0MOB2ci6TWbOeFikl+irffhhxe2O7Prpz+fCySpFJ52ek6cSTH/0GIOod1ZkLIULld8n3eWiSZzf1E6JoGMNw3Msv7xLmf/Co1gWHcjFEkXG7Ev/vzkhbvlHIs9lFZPo0mQqF8j3fV9GKUA==" Dec 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Dec 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 08 14:06:49 volumio-reception go-librespot[5752]: time="2025-12-08T14:06:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 08 14:06:49 volumio-reception systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 08 14:06:49 volumio-reception systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 08 14:06:50 volumio-reception volumio[4411]: info: Getting Spotify volume Dec 08 14:06:50 volumio-reception volumio[4411]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 08 14:06:50 volumio-reception volumio[4411]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 08 14:06:50 volumio-reception volumio[4411]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 08 14:06:50 volumio-reception volumio[4411]: errno: -111, Dec 08 14:06:50 volumio-reception volumio[4411]: code: 'ECONNREFUSED', Dec 08 14:06:50 volumio-reception volumio[4411]: syscall: 'connect', Dec 08 14:06:50 volumio-reception volumio[4411]: address: '127.0.0.1', Dec 08 14:06:50 volumio-reception volumio[4411]: port: 9879, Dec 08 14:06:50 volumio-reception volumio[4411]: response: undefined Dec 08 14:06:50 volumio-reception volumio[4411]: } Dec 08 14:06:50 volumio-reception volumio[4411]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 08 14:06:50 volumio-reception sudo[5773]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-08 14:05' Dec 08 14:06:50 volumio-reception sudo[5773]: 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"