Dec 12 19:45:03 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:45:03 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:45:03 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:45:03 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:45:10 volumio-socrates ntpd[954]: PROTO: 31.58.102.164 unlink local addr 192.168.1.120 -> Dec 12 19:45:13 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:45:13 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:45:23 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:45:23 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:45:23 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:45:23 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:45:23 volumio-socrates systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... Dec 12 19:45:25 volumio-socrates systemd[1]: apt-daily-upgrade.service: Deactivated successfully. Dec 12 19:45:25 volumio-socrates systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities. Dec 12 19:45:25 volumio-socrates systemd[1]: apt-daily-upgrade.service: Consumed 2.031s CPU time. Dec 12 19:45:30 volumio-socrates volumio[3064]: verbose: New Socket.io Connection to 192.168.1.120 from 192.168.1.141 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:146.0) Gecko/20100101 Firefox/146.0 Engine version: 3 Transport: polling Total Clients: 4 Dec 12 19:45:30 volumio-socrates volumio[3064]: info: Enabling plugin mixcloud Dec 12 19:45:30 volumio-socrates volumio[3064]: info: Loading plugin "mixcloud"... Dec 12 19:45:31 volumio-socrates volumio[3064]: info: PLUGIN START: mixcloud Dec 12 19:45:31 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 19:45:31 volumio-socrates volumio[3064]: info: [1765565131925] CoreMusicLibrary::Adding element Mixcloud Dec 12 19:45:31 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 19:45:31 volumio-socrates volumio[3064]: Cannot find translation for source YouTube2 Dec 12 19:45:31 volumio-socrates volumio[3064]: Cannot find translation for source Mixcloud Dec 12 19:45:31 volumio-socrates volumio[3064]: info: Done. Dec 12 19:45:33 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:45:33 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetVisibleSources Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 12 19:45:38 volumio-socrates volumio[3064]: info: Received Get System Info Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 19:45:38 volumio-socrates volumio[3064]: info: Discovery: Getting this device information Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:45:38 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:45:38 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 12 19:45:43 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:45:43 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:45:43 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:45:43 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:45:44 volumio-socrates volumio[3064]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/soundcloud/volumio/bookworm/armhf Dec 12 19:45:45 volumio-socrates volumio[3064]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/soundcloud/volumio/bookworm/armhf Dec 12 19:45:45 volumio-socrates volumio[3064]: info: Folder /tmp/plugins removed Dec 12 19:45:46 volumio-socrates volumio[3064]: info: Check plugin dependencies Dec 12 19:45:46 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 19:45:46 volumio-socrates volumio[3064]: info: Checking if plugin already exists Dec 12 19:45:46 volumio-socrates volumio[3064]: info: Rename folder Dec 12 19:45:46 volumio-socrates volumio[3064]: info: Folder /tmp/downloaded_plugin.zip removed Dec 12 19:45:46 volumio-socrates volumio[3064]: info: Move to category Dec 12 19:45:46 volumio-socrates volumio[3064]: info: Checking if install.sh is present Dec 12 19:45:46 volumio-socrates volumio[3064]: info: Executing install.sh Dec 12 19:45:46 volumio-socrates sudo[10997]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/soundcloud/install.sh Dec 12 19:45:46 volumio-socrates sudo[10997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 19:45:46 volumio-socrates sudo[10997]: pam_unix(sudo:session): session closed for user root Dec 12 19:45:46 volumio-socrates volumio[3064]: info: SoundCloud plugin installed Dec 12 19:45:46 volumio-socrates volumio[3064]: Plugin install end detected on script Dec 12 19:45:46 volumio-socrates volumio[3064]: info: Install script completed Dec 12 19:45:46 volumio-socrates volumio[3064]: info: Adding reference to registry Dec 12 19:45:46 volumio-socrates volumio[3064]: info: Done installing plugin. Dec 12 19:45:47 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 12 19:45:47 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 12 19:45:47 volumio-socrates volumio[3064]: info: Folder /tmp/plugins removed Dec 12 19:45:47 volumio-socrates volumio[3064]: info: Folder /tmp/downloaded_plugin.zip removed Dec 12 19:45:47 volumio-socrates volumio[3064]: info: Folder /data/temp removed Dec 12 19:45:47 volumio-socrates volumio[3064]: info: Enabling plugin soundcloud Dec 12 19:45:47 volumio-socrates volumio[3064]: info: Loading plugin "soundcloud"... Dec 12 19:45:48 volumio-socrates volumio[3064]: info: PLUGIN START: soundcloud Dec 12 19:45:48 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 19:45:48 volumio-socrates volumio[3064]: info: [1765565148450] CoreMusicLibrary::Adding element SoundCloud Dec 12 19:45:48 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 19:45:48 volumio-socrates volumio[3064]: Cannot find translation for source YouTube2 Dec 12 19:45:48 volumio-socrates volumio[3064]: Cannot find translation for source Mixcloud Dec 12 19:45:48 volumio-socrates volumio[3064]: Cannot find translation for source SoundCloud Dec 12 19:45:48 volumio-socrates volumio[3064]: info: Done. Dec 12 19:45:53 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:45:53 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:45:55 volumio-socrates volumio[3064]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Dec 12 19:45:56 volumio-socrates volumio[3064]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Dec 12 19:45:56 volumio-socrates volumio[3064]: info: Folder /tmp/plugins removed Dec 12 19:45:57 volumio-socrates volumio[3064]: info: Check plugin dependencies Dec 12 19:45:57 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 12 19:45:57 volumio-socrates volumio[3064]: info: Checking if plugin already exists Dec 12 19:45:57 volumio-socrates volumio[3064]: info: Rename folder Dec 12 19:45:57 volumio-socrates volumio[3064]: info: Folder /tmp/downloaded_plugin.zip removed Dec 12 19:45:57 volumio-socrates volumio[3064]: info: Move to category Dec 12 19:45:59 volumio-socrates volumio[3064]: info: Checking if install.sh is present Dec 12 19:45:59 volumio-socrates volumio[3064]: info: Executing install.sh Dec 12 19:45:59 volumio-socrates sudo[11047]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh Dec 12 19:45:59 volumio-socrates sudo[11047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 19:45:59 volumio-socrates volumio[3064]: info: Installing Go-librespot Dec 12 19:45:59 volumio-socrates volumio[3064]: info: Checking old vollibrespot installs Dec 12 19:45:59 volumio-socrates systemd[1]: Reloading. Dec 12 19:46:01 volumio-socrates volumio[3064]: info: Downloading daemon Dec 12 19:46:01 volumio-socrates systemd[1]: Starting apt-daily.service - Daily apt download activities... Dec 12 19:46:02 volumio-socrates nmbd[2397]: [2025/12/12 19:46:02.671259, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Dec 12 19:46:02 volumio-socrates nmbd[2397]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.120 for name WORKGROUP<1d>. Dec 12 19:46:02 volumio-socrates nmbd[2397]: This response was from IP 192.168.1.124, reporting an IP address of 192.168.1.124. Dec 12 19:46:03 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:46:03 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:46:03 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:46:03 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:46:03 volumio-socrates volumio[3064]: info: Creating directories Dec 12 19:46:03 volumio-socrates volumio[3064]: info: Creating data directory Dec 12 19:46:03 volumio-socrates volumio[3064]: info: Creating Start Script Dec 12 19:46:03 volumio-socrates systemd[1]: Reloading. Dec 12 19:46:04 volumio-socrates systemd[1]: apt-daily.service: Deactivated successfully. Dec 12 19:46:04 volumio-socrates systemd[1]: Finished apt-daily.service - Daily apt download activities. Dec 12 19:46:04 volumio-socrates systemd[1]: apt-daily.service: Consumed 2.249s CPU time. Dec 12 19:46:04 volumio-socrates sudo[11047]: pam_unix(sudo:session): session closed for user root Dec 12 19:46:04 volumio-socrates volumio[3064]: Plugin install end detected on script Dec 12 19:46:04 volumio-socrates volumio[3064]: info: Install script completed Dec 12 19:46:05 volumio-socrates volumio[3064]: info: Adding reference to registry Dec 12 19:46:05 volumio-socrates volumio[3064]: info: Done installing plugin. Dec 12 19:46:05 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 12 19:46:05 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 12 19:46:05 volumio-socrates volumio[3064]: info: Folder /tmp/plugins removed Dec 12 19:46:05 volumio-socrates volumio[3064]: info: Folder /tmp/downloaded_plugin.zip removed Dec 12 19:46:05 volumio-socrates volumio[3064]: info: Folder /data/temp removed Dec 12 19:46:06 volumio-socrates volumio[3064]: info: Enabling plugin spop Dec 12 19:46:06 volumio-socrates volumio[3064]: info: Loading plugin "spop"... Dec 12 19:46:07 volumio-socrates volumio[3064]: info: PLUGIN START: spop Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Creating Spotify config file Dec 12 19:46:07 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Done. Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Enabling plugin spop Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Loading plugin "spop"... Dec 12 19:46:07 volumio-socrates volumio[3064]: info: PLUGIN START: spop Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Creating Spotify config file Dec 12 19:46:07 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Done. Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Spotify config file written Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Spotify config file written Dec 12 19:46:07 volumio-socrates volumio[3064]: info: No need to fix Spotify hosts Dec 12 19:46:07 volumio-socrates volumio[3064]: info: No need to fix Spotify hosts Dec 12 19:46:07 volumio-socrates sudo[11179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 12 19:46:07 volumio-socrates sudo[11179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 19:46:07 volumio-socrates sudo[11181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 12 19:46:07 volumio-socrates sudo[11181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 12 19:46:07 volumio-socrates 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 12 19:46:07 volumio-socrates 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 12 19:46:07 volumio-socrates volumio[3064]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 12 19:46:07 volumio-socrates volumio[3064]: SPOTIFY: BQDlmiGFrxW2aYqGt7U9PTmXdzLWS86SIsJs9tSeEbQ9ETAOvaq4dP1fPZF95mikcVvVgyPfZ9yguGkEbNPipJdJ1cmsQxuY7TIRhgdKf2Es0chjUyANenzYfYvZyTqIv8vq48ZwLqwA4qEgO4YG8TGlQ_bbCw-2SlHpiSv5JR3vf2FKwrleU0l40xe7I7xj554Ou7PEjZtiIYfYn6ku4eqB0XVL2ZWHr4F2AojerDsQQTIHaxSJ_QZ3ukVH-OOEncYKEDLZ9B8zpeB7jR2lNAKUiEGXg1qzP4A Dec 12 19:46:07 volumio-socrates volumio[3064]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 12 19:46:07 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:07 volumio-socrates go-librespot[11184]: go-librespot daemon starting... Dec 12 19:46:07 volumio-socrates volumio[3064]: info: New Spotify access token = BQDlmiGFrxW2aYqGt7U9PTmXdzLWS86SIsJs9tSeEbQ9ETAOvaq4dP1fPZF95mikcVvVgyPfZ9yguGkEbNPipJdJ1cmsQxuY7TIRhgdKf2Es0chjUyANenzYfYvZyTqIv8vq48ZwLqwA4qEgO4YG8TGlQ_bbCw-2SlHpiSv5JR3vf2FKwrleU0l40xe7I7xj554Ou7PEjZtiIYfYn6ku4eqB0XVL2ZWHr4F2AojerDsQQTIHaxSJ_QZ3ukVH-OOEncYKEDLZ9B8zpeB7jR2lNAKUiEGXg1qzP4A Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 12 19:46:07 volumio-socrates sudo[11179]: pam_unix(sudo:session): session closed for user root Dec 12 19:46:07 volumio-socrates sudo[11181]: pam_unix(sudo:session): session closed for user root Dec 12 19:46:07 volumio-socrates volumio[3064]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 12 19:46:07 volumio-socrates volumio[3064]: SPOTIFY: BQBDCgSA1Bb7YWyY5AR3PwNbD2Td7TJ0UA3xo0CIfLrSX9eK9LbxCCfU71E0soT6YO2eklUzjt0tmjTqhVThOk-_KnCksHhF-cagalpoir5Z9jpmyrOD_MKgwnTQ3b99B7EZDKrauHEcUR_991dheWwm5Bqvz2zQKOy5Y31ccKfcrPtOsZm5EZ3IwOdgxzAr3tfChJpAAP47_-1m8CYbCPuq7Q9Vucg4sntkTwzWljPTYN8YBpLdfsrGgYaXlicDt4Z4b3RUbvhbK7eWhQ78Y6-AGaWynnJTsKo Dec 12 19:46:07 volumio-socrates volumio[3064]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 12 19:46:07 volumio-socrates volumio[3064]: info: New Spotify access token = BQBDCgSA1Bb7YWyY5AR3PwNbD2Td7TJ0UA3xo0CIfLrSX9eK9LbxCCfU71E0soT6YO2eklUzjt0tmjTqhVThOk-_KnCksHhF-cagalpoir5Z9jpmyrOD_MKgwnTQ3b99B7EZDKrauHEcUR_991dheWwm5Bqvz2zQKOy5Y31ccKfcrPtOsZm5EZ3IwOdgxzAr3tfChJpAAP47_-1m8CYbCPuq7Q9Vucg4sntkTwzWljPTYN8YBpLdfsrGgYaXlicDt4Z4b3RUbvhbK7eWhQ78Y6-AGaWynnJTsKo Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 12 19:46:07 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:07+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:07 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:07+01:00" level=debug msg="no app state found" Dec 12 19:46:07 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:07+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:07 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:07+01:00" level=info msg="generated new device id: 2d06ecd896d3ded6283c6bc08f7b09a42259430b" Dec 12 19:46:07 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:07 volumio-socrates volumio[3064]: SPOTIFY: User informations: {"country":"NL","display_name":"Jory","email":"joryvd@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/116610977"},"followers":{"href":null,"total":20},"href":"https://api.spotify.com/v1/users/116610977","id":"116610977","images":[],"product":"premium","type":"user","uri":"spotify:user:116610977"} Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Spotify Successfully logged in Dec 12 19:46:07 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 19:46:07 volumio-socrates volumio[3064]: info: [1765565167919] CoreMusicLibrary::Adding element Spotify Dec 12 19:46:07 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 19:46:07 volumio-socrates volumio[3064]: Cannot find translation for source YouTube2 Dec 12 19:46:07 volumio-socrates volumio[3064]: Cannot find translation for source Mixcloud Dec 12 19:46:07 volumio-socrates volumio[3064]: Cannot find translation for source SoundCloud Dec 12 19:46:07 volumio-socrates volumio[3064]: Cannot find translation for source Spotify Dec 12 19:46:07 volumio-socrates volumio[3064]: SPOTIFY: User informations: {"country":"NL","display_name":"Jory","email":"joryvd@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/116610977"},"followers":{"href":null,"total":20},"href":"https://api.spotify.com/v1/users/116610977","id":"116610977","images":[],"product":"premium","type":"user","uri":"spotify:user:116610977"} Dec 12 19:46:07 volumio-socrates volumio[3064]: info: Spotify Successfully logged in Dec 12 19:46:07 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 12 19:46:07 volumio-socrates volumio[3064]: info: [1765565167963] CoreMusicLibrary::Adding element Spotify Dec 12 19:46:07 volumio-socrates volumio[3064]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 19:46:07 volumio-socrates volumio[3064]: Cannot find translation for source YouTube2 Dec 12 19:46:07 volumio-socrates volumio[3064]: Cannot find translation for source Mixcloud Dec 12 19:46:07 volumio-socrates volumio[3064]: Cannot find translation for source SoundCloud Dec 12 19:46:07 volumio-socrates volumio[3064]: Cannot find translation for source Spotify Dec 12 19:46:08 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:08+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 12 19:46:08 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:08+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 12 19:46:08 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:08+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 12 19:46:08 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:08+01:00" level=info msg="zeroconf server listening on port 44407" Dec 12 19:46:08 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:08+01:00" level=debug msg="obtained new client token: AADiiGfs6bYszKkX5PBCm1fQ24XuEgNp1Qa0cIB8quB4GKLja9ZxCtIdrjIYk3AMxOdbqYGZU+J6Nfv3gP3t3RNq6tWRX3r62sg1O9HXjkwIvcPgz05x4UMarONW9pBNc2pja1SnanVFwchwteTerihIRKAVWSyGVENVX/Jo3NGC+Tt2EgPP1UhSCuohQchnYaVNISIq+7MBRfDDnc/ZyO1INAn80/J3mu+6QkGtw5NESTdETkmmuCg=" Dec 12 19:46:08 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:08 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:08+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:08 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:08+01:00" level=debug msg="completed challenge" Dec 12 19:46:08 volumio-socrates go-librespot[11185]: time="2025-12-12T19:46:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:08 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:08 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:10 volumio-socrates volumio[3064]: info: go-librespot daemon successfully initialized Dec 12 19:46:10 volumio-socrates volumio[3064]: info: go-librespot daemon successfully initialized Dec 12 19:46:11 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 12 19:46:11 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:11 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:11 volumio-socrates go-librespot[11196]: go-librespot daemon starting... Dec 12 19:46:11 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:11+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:11 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:11+01:00" level=debug msg="app state loaded" Dec 12 19:46:11 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:11+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:11 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:11 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:11+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 12 19:46:11 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:11+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 12 19:46:11 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:11+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 12 19:46:11 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:11+01:00" level=info msg="zeroconf server listening on port 45409" Dec 12 19:46:11 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:11+01:00" level=debug msg="obtained new client token: AABT6fyQRMAz9GrWeh4hOrMFpN12xRRD/ch8ZfDxZMNwckQzJV3/QiFnlIjt+wbx64oIv9d5s9iIRgXmWH7S6rTf9h0K66vJXohsDzmoWCkTj9PJslcF3B0fkECiL4AQftiNctW98Am8pCnxXFFZSWCLF5mk8gUIOCsMzNQm81aVwyUG8ytpxcmKIt/NbV23/Tu5a/MAClraZFC6jTC/X5fyVPCn1iVA5He8/4abONp3U+gt/IZPf+Rgzw==" Dec 12 19:46:11 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:12 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:12+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:12 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:12+01:00" level=debug msg="completed challenge" Dec 12 19:46:12 volumio-socrates go-librespot[11197]: time="2025-12-12T19:46:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:12 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:12 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:13 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:46:13 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:46:13 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:13 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:13 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:13 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:15 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 12 19:46:15 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:15 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:15 volumio-socrates go-librespot[11229]: go-librespot daemon starting... Dec 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+01:00" level=debug msg="app state loaded" Dec 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+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 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+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 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+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 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+01:00" level=info msg="zeroconf server listening on port 45559" Dec 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+01:00" level=debug msg="obtained new client token: AABf5UinMMbC9tLU0A+tYw6cB5VM9TIsXYCLxkaNFUcaoo8bcsQ1za2tf8fWgs/gEPhEorS4WFdNSIEvOJSO3DwF9+EATccjTpn36Wo+AwPiIHbee0r5aiKyCOgcAo463eYG2FHZrWCE8yiaSc5Z1uhIBdcj2a99L8nEvHiBVUoz9en5KfxHiTSu13OQz01wWywJz1RdehxvtTM5ZbF+LVjb2WRtz2CzliYBs0omAjpXnz1pfu/vIdoTgw==" Dec 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+01:00" level=debug msg="completed challenge" Dec 12 19:46:15 volumio-socrates go-librespot[11230]: time="2025-12-12T19:46:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:15 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:15 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:16 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:16 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:19 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 12 19:46:19 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:19 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:19 volumio-socrates go-librespot[11239]: go-librespot daemon starting... Dec 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+01:00" level=debug msg="app state loaded" Dec 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+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 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+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 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+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 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+01:00" level=info msg="zeroconf server listening on port 41459" Dec 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+01:00" level=debug msg="obtained new client token: AACik9rxmtNjYIldAwV4vIGQtVmWxu7QolEE8s2gFAYh7hKgyu4DD+nDkIopEFCjxQz6wVOoNMXJ4Pwn6n5tU8FEoie78xUBUGzcaXTA/B+BRJ9uwGMQsMW4iJ6ld6YD92qcwURR41Fy5RYJ1oJLafuisCvoL8Il1La7nzu8Uvi+0j7zsTMKhx8Oo6vnlnnjDAzJImeGQbyGc5f811ELz1RjKY8E9+sHMRZDIzDgizmmr6vwjGSNheeyNw==" Dec 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+01:00" level=debug msg="completed challenge" Dec 12 19:46:19 volumio-socrates go-librespot[11240]: time="2025-12-12T19:46:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:19 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:19 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:19 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:19 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:22 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 12 19:46:22 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:22 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:22 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:22 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:22 volumio-socrates go-librespot[11261]: go-librespot daemon starting... Dec 12 19:46:22 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:22+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:22 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:22+01:00" level=debug msg="app state loaded" Dec 12 19:46:22 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:22+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:22 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:23 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:23+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 12 19:46:23 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:23+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 12 19:46:23 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:23+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 12 19:46:23 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:23+01:00" level=info msg="zeroconf server listening on port 44047" Dec 12 19:46:23 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:23+01:00" level=debug msg="obtained new client token: AABBmQrPhF3rf3eMTr4lFV9y8qARzby/QGVbBgJWZCEoyuiWhxwbwFuNqNrTf6LsuQJJroAWDnpz4wGzqF2hmT73yiABeFLTc5uPtrkn9Xh1hKUxi30MtOa1mPS7NjrfEdvedhgSL54Om9Mo9bUiGgJScRb2u063P9Phade+abTUDUeUz7dzrM4DlEnJB87uRCNrhbISd/8dpH0qZZWGGf4+JbD/63LNRX06WBgSd+B/m+p73Ce41Ls=" Dec 12 19:46:23 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:23 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:23+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:23 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:23+01:00" level=debug msg="completed challenge" Dec 12 19:46:23 volumio-socrates go-librespot[11262]: time="2025-12-12T19:46:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:23 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:23 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:23 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:46:23 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:46:23 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:46:23 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:46:25 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:25 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:26 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 12 19:46:26 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:26 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:26 volumio-socrates go-librespot[11280]: go-librespot daemon starting... Dec 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+01:00" level=debug msg="app state loaded" Dec 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+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 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+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 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+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 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+01:00" level=info msg="zeroconf server listening on port 43459" Dec 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+01:00" level=debug msg="obtained new client token: AADzq8+HQvlPHSjsPtqpeqCBkwZBXl6tDy8eJv/mZczbJiSAKbyMxhhZAPHOqUTO51lUh+mwJFLtG2TtTNLLraectWyHudDYPS+0BJNtKd5eFVS1iUcGBnVBTdoCu/cGM9A/ABFEB/JSXm4Pj6FZBsF0+FDzbjaamgx9qrrXASj2tQcYNs2IUWt7s9VRfc0eUcM0Tce7lvKdO4408Gkfb6bIme0SE4/zfF3u2kP3fgRWKEUe5RRAzqrPdg==" Dec 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+01:00" level=debug msg="completed challenge" Dec 12 19:46:26 volumio-socrates go-librespot[11281]: time="2025-12-12T19:46:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:26 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:26 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:28 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:28 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:30 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 12 19:46:30 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:30 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:30 volumio-socrates go-librespot[11288]: go-librespot daemon starting... Dec 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+01:00" level=debug msg="app state loaded" Dec 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+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 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+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 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+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 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+01:00" level=info msg="zeroconf server listening on port 36335" Dec 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+01:00" level=debug msg="obtained new client token: AABjv0AOGguuUXKeODdf8jk/Y2TafIQ7leJ1hhbQFM39S92LA8QJ4UJlEPNE5lq0osaqaL6a1bKSYHc2jwAOAcAYxy20EzMO0kxoyMq1e5+QvVkSZnyXRs8uY7+r2zLL7jPt+fqkEIcuBEMxFod3uGFZm19oA1MxepxpFBWk0AucP79UJ0q3Y7fIuZ5HEaexwCJlOvD5hzJ8NHtYJfl6HpZD/U57DfeAMujJZms1TdZYEsJMhbDvgv/8Ww==" Dec 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+01:00" level=debug msg="completed challenge" Dec 12 19:46:30 volumio-socrates go-librespot[11289]: time="2025-12-12T19:46:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:30 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:30 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:31 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:31 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:33 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:46:33 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:46:33 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 12 19:46:33 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:33 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:33 volumio-socrates go-librespot[11324]: go-librespot daemon starting... Dec 12 19:46:33 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:33+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:33 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:33+01:00" level=debug msg="app state loaded" Dec 12 19:46:33 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:33+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:33 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:33 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 12 19:46:33 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:33+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 12 19:46:33 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:33+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 12 19:46:33 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:33+01:00" level=info msg="zeroconf server listening on port 44301" Dec 12 19:46:33 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:33+01:00" level=debug msg="obtained new client token: AACDo0rKvKN/9C08mRXXXEUFhuyIg3QoRWop9JtapEe7B1VF+rWyyHxNoo9NEZmYoFhHcmDOPDsZWwQnW4YTwPBXZbUrWkKWM+qfGJDBtY26AVYV5tlCW3EzOX6PlT+SQcaRA4jD2FfsJUDEAyc1im9oDNE3Djtms3k5Um7PorRLTEJDJBl1qtvELOEKJI7/eY+T6WsKNF2ARMHN0iDVn6A1OVT3jnAFCMdp4O6SM5o2VCpTV0xGu/OGUw==" Dec 12 19:46:34 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:34+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 12 19:46:34 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Dec 12 19:46:34 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:34+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:34 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:34+01:00" level=debug msg="completed challenge" Dec 12 19:46:34 volumio-socrates go-librespot[11325]: time="2025-12-12T19:46:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:34 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:34 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:34 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:34 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:37 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 12 19:46:37 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:37 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:37 volumio-socrates go-librespot[11332]: go-librespot daemon starting... Dec 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+01:00" level=debug msg="app state loaded" Dec 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+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 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+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 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+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 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+01:00" level=info msg="zeroconf server listening on port 38023" Dec 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+01:00" level=debug msg="obtained new client token: AAB1NfFnFVGmCKMco5Hy/EBuqewEXlV+Q7bKdV0EEEsaD+YAUOWxlII4Q+usL8pr++wC8G0yNF6nAmK3G42ihU1SJAbXJg3wQQZ3EO/w3Z3QqqEJdOGahfbFAIv25n0L0w8DdNl6UrqeCJ6WIpQmUBIzN9I2I7Vy6wrgxy/lvMUVFhPx2UiSwU0Kfgj0cowkb5xr0ZjrIu5AWmibhB5zrT67Pt17gJ32F+1CE5oDV/00Z/0BHCLkJeRZvg==" Dec 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:37 volumio-socrates go-librespot[11333]: time="2025-12-12T19:46:37+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 12 19:46:37 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:37 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:37 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:37 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:40 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 12 19:46:40 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:40 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:40 volumio-socrates go-librespot[11342]: go-librespot daemon starting... Dec 12 19:46:40 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:40 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:40 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46:40+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:40 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46:40+01:00" level=debug msg="app state loaded" Dec 12 19:46:40 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46:40+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:40 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:41 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46: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 12 19:46:41 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46: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 12 19:46:41 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46: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 12 19:46:41 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46:41+01:00" level=info msg="zeroconf server listening on port 45373" Dec 12 19:46:41 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46:41+01:00" level=debug msg="obtained new client token: AADc/MA0MYK0Usm4VEtre3chJunQUVumXD9XBt6bCPMKspm/qhiKXk/eLUPTNml4XTZcufzp4vDM78TRrE+yFDSf37SSS3iGACjHy/RStrSjZbsgJqXPf+woNvw4UihGjA2bDdMYgzv22ahFtOYRFz0U4yxZFdklKdAkpe7UzRsb0Ut5FKRK9psFbGl5lFnMEwPeneKLYeWuZhHTOcsFveAHGn/vPoY5Jo8dE0g2Qy4txrQJFqehD30=" Dec 12 19:46:41 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:41 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46:41+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:41 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46:41+01:00" level=debug msg="completed challenge" Dec 12 19:46:41 volumio-socrates go-librespot[11343]: time="2025-12-12T19:46:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:41 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:41 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:43 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:46:43 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:46:43 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:46:43 volumio-socrates volumio[3064]: info: Listing playlists Dec 12 19:46:43 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:43 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:44 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 12 19:46:44 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:44 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:44 volumio-socrates go-librespot[11375]: go-librespot daemon starting... Dec 12 19:46:44 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:44+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:44 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:44+01:00" level=debug msg="app state loaded" Dec 12 19:46:44 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:44+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:44 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:44 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:44+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 12 19:46:44 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:44+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 12 19:46:44 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:44+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 12 19:46:44 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:44+01:00" level=info msg="zeroconf server listening on port 34757" Dec 12 19:46:44 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:44+01:00" level=debug msg="obtained new client token: AAA7PEdPLVL7m53V/lgbC2uF/MVzYCC+0RBdsyoIfvZmEhxxpypjG5HZcgraGyQ3u+/Ev0nHIUB0D5tC49h5Gb2Fzc4iQe1KDmBm88I2ki/PZ6iR+xWlh/2HlxQmbw+A0duo8uqmVlShEG4wIY5hNfWyvVT7Y3f+PXKrDXKYUSwJr+uyix72LRg+bOJw3LXclMr+SrHVJuJEluMqXUWoVKI+9w6XDDh3Jd+7VP+AMOjif1YeJukMMJj0Qg==" Dec 12 19:46:44 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:45 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:45+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:45 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:45+01:00" level=debug msg="completed challenge" Dec 12 19:46:45 volumio-socrates go-librespot[11376]: time="2025-12-12T19:46:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:45 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:45 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:46 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:46 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:48 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 12 19:46:48 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:48 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:48 volumio-socrates go-librespot[11384]: go-librespot daemon starting... Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+01:00" level=debug msg="app state loaded" Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+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 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+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 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+01:00" level=info msg="zeroconf server listening on port 40215" Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+01:00" level=debug msg="obtained new client token: AADtmfZNEei5+RKvo1F84cqHeyb7M0swsGBtfRbTP4G4aZHJEKjohc2BcKGDmDbuZrd2bEe6dQNWIXbstsVeMMAsZFkhp+6MpG+hLOeAx0KsY1gQZ306m8HoNGsc0bKQkp4IAcjoTDrRY9dRtT9wz9Qx+xHPRAF0s1JY2TS+5DhYy/58yYGM1VvaEvOlnZt0VJGQ4GxedzEU7PkuqPEmtQOaAc9QL0ZqaXtWYg36eDyd1ZaOevXpea+SBg==" Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+01:00" level=debug msg="completed challenge" Dec 12 19:46:48 volumio-socrates go-librespot[11385]: time="2025-12-12T19:46:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:48 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:48 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:49 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:49 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:51 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Dec 12 19:46:51 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:51 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:51 volumio-socrates go-librespot[11395]: go-librespot daemon starting... Dec 12 19:46:51 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:51+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:51 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:51+01:00" level=debug msg="app state loaded" Dec 12 19:46:51 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:51+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:51 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:52 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 12 19:46:52 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:52+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 12 19:46:52 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:52+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 12 19:46:52 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:52+01:00" level=info msg="zeroconf server listening on port 43067" Dec 12 19:46:52 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:52+01:00" level=debug msg="obtained new client token: AAAYltte4tBfWqDDApNRGQqtcFT0GtYKROHBrPkZlhhvTJcjeG4LBgwO2UphunRH/uuk3q24EJ2KXyf72iB325jev/frPqHwNaTStFi0ocZRx4qdnhumAALWsmC3ePocZwvH8Xa3Anm7pQTNAEoJbJJ+CScacjm6JpIIi5ndfVYxJCZOwF4+gbjZs7BlquUhns3N0rSpnY1J5ChbuTXMHHAxnt0NhaeXU/DRbXM3Vn2//vUG3qaJYtw=" Dec 12 19:46:52 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:52 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:52+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:52 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:52+01:00" level=debug msg="completed challenge" Dec 12 19:46:52 volumio-socrates go-librespot[11396]: time="2025-12-12T19:46:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:52 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:52 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:52 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:52 volumio-socrates volumio[3064]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:53 volumio-socrates volumio[3064]: info: CoreCommandRouter::volumioGetState Dec 12 19:46:53 volumio-socrates volumio[3064]: info: CorePlayQueue::getTrack 0 Dec 12 19:46:55 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 12 19:46:55 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:55 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:55 volumio-socrates go-librespot[11429]: go-librespot daemon starting... Dec 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+01:00" level=debug msg="app state loaded" Dec 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+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 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+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 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+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 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+01:00" level=info msg="zeroconf server listening on port 39107" Dec 12 19:46:55 volumio-socrates volumio[3064]: info: Initializing connection to go-librespot Websocket Dec 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+01:00" level=debug msg="new websocket client" Dec 12 19:46:55 volumio-socrates volumio[3064]: info: Connection to go-librespot Websocket established Dec 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+01:00" level=debug msg="obtained new client token: AACMLud6vNHQLuqwNxHm8V73+cumPIlo5Suxk6171O6+YjA8w7Pm07UVkwVTe2PQZvfg4nRJthA3EFX/Ha+PInDU89SX0ZNOaE3HLlVd9d4yEGdjbIwF9I2y6CXmdm2JJUfSNC46gFnEjs0z4fWcCWYIzswsbN/xQ9Jkz92eRifSQMqxlIaEY13/deHXwJSapg8oSctltNsASic44bD10ZWda24wFZCvvTkNoKZ38QH9Xo0JpygeF08ELA==" Dec 12 19:46:55 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:56 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:56+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:56 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:56+01:00" level=debug msg="completed challenge" Dec 12 19:46:56 volumio-socrates go-librespot[11430]: time="2025-12-12T19:46:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:56 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:56 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:56 volumio-socrates volumio[3064]: info: Connection to go-librespot Websocket closed Dec 12 19:46:58 volumio-socrates volumio[3064]: info: Getting Spotify volume Dec 12 19:46:58 volumio-socrates volumio[3064]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 19:46:58 volumio-socrates volumio[3064]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 12 19:46:58 volumio-socrates volumio[3064]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 12 19:46:58 volumio-socrates volumio[3064]: errno: -111, Dec 12 19:46:58 volumio-socrates volumio[3064]: code: 'ECONNREFUSED', Dec 12 19:46:58 volumio-socrates volumio[3064]: syscall: 'connect', Dec 12 19:46:58 volumio-socrates volumio[3064]: address: '127.0.0.1', Dec 12 19:46:58 volumio-socrates volumio[3064]: port: 9879, Dec 12 19:46:58 volumio-socrates volumio[3064]: response: undefined Dec 12 19:46:58 volumio-socrates volumio[3064]: } Dec 12 19:46:58 volumio-socrates volumio[3064]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 19:46:59 volumio-socrates systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 12 19:46:59 volumio-socrates systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:59 volumio-socrates systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 12 19:46:59 volumio-socrates go-librespot[11450]: go-librespot daemon starting... Dec 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+01:00" level=info msg="running go-librespot 0.4.0" Dec 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+01:00" level=debug msg="app state loaded" Dec 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+01:00" level=debug msg="stored credentials not found" Dec 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+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 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+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 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+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 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+01:00" level=info msg="zeroconf server listening on port 40157" Dec 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+01:00" level=debug msg="obtained new client token: AADm8WYY5LR1hZ7qKxiQtxIR2AHJbO3FhTF50vUrNu07+eBWMhjCWxteOhq4gtawkNqq3t3oOapq+/P38wzE4MnIw8+3zN5AgvSFSfR5C2q9l5HRnMvF7FUeKgIORj+ozQzsNvEfHjslMS3gP+S5+9gUsdNVLKaKVWsohMV10VnV5r9RZyu2Mni7SsmTyUOWDZ24/LWyHBuwabNqx7xmS9JjLqqrMXtlItu+lrUrePk7QH62esWy2l0qbg==" Dec 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+01:00" level=debug msg="completed keyexchange" Dec 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+01:00" level=debug msg="completed challenge" Dec 12 19:46:59 volumio-socrates go-librespot[11451]: time="2025-12-12T19:46:59+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 12 19:46:59 volumio-socrates systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 12 19:46:59 volumio-socrates systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 12 19:46:59 volumio-socrates sudo[11460]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-12 19:45' Dec 12 19:46:59 volumio-socrates sudo[11460]: 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"