Oct 11 14:49:01 volumiofloersbach volumio[1349]: Searching all installed plugins Oct 11 14:49:01 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 14:49:01 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: , search Oct 11 14:49:01 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 11 14:49:01 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 11 14:49:01 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 11 14:49:01 volumiofloersbach volumio[1349]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 11 14:49:01 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 11 14:49:01 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: jellyfin , search Oct 11 14:49:01 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Oct 11 14:49:06 volumiofloersbach volumio[1349]: npm notice Oct 11 14:49:06 volumiofloersbach volumio[1349]: npm notice New major version of npm available! 9.8.0 -> 12.2.0 Oct 11 14:49:06 volumiofloersbach volumio[1349]: npm notice Changelog: Oct 11 14:49:06 volumiofloersbach volumio[1349]: npm notice Run `npm install -g npm@12.2.0` to update! Oct 11 14:49:06 volumiofloersbach volumio[1349]: npm notice Oct 11 14:49:06 volumiofloersbach volumio[1349]: info: [ytmusic] Innertube support service: Deno not installed or otherwise failed to start: Command failed: npx --no-install --yes deno --version Oct 11 14:49:06 volumiofloersbach volumio[1349]: npm notice Oct 11 14:49:06 volumiofloersbach volumio[1349]: npm notice New major version of npm available! 9.8.0 -> 12.2.0 Oct 11 14:49:06 volumiofloersbach volumio[1349]: npm notice Changelog: Oct 11 14:49:06 volumiofloersbach volumio[1349]: npm notice Run `npm install -g npm@12.2.0` to update! Oct 11 14:49:06 volumiofloersbach volumio[1349]: npm notice Oct 11 14:49:06 volumiofloersbach volumio[1349]: info: [ytmusic] Innertube support service: Start service with Node Oct 11 14:49:06 volumiofloersbach volumio[1349]: error: Search in plugin mpd timed out Oct 11 14:49:06 volumiofloersbach volumio[1349]: error: Search in plugin webradio timed out Oct 11 14:49:06 volumiofloersbach volumio[1349]: error: Failed search in plugin mpd: Error: Unable to resolve or reject the same promise twice Oct 11 14:49:07 volumiofloersbach volumio[1349]: error: Failed search in plugin webradio: Error: Unable to resolve or reject the same promise twice Oct 11 14:49:09 volumiofloersbach volumio[1349]: info: [ytmusic] Innertube support service: result: {"status":"started","server":{"address":"127.0.0.1","port":36973}} Oct 11 14:49:09 volumiofloersbach volumio[1349]: info: [ytmusic] Innertube support service running at http://127.0.0.1:36973 Oct 11 14:49:14 volumiofloersbach volumio[1349]: [YOUTUBEJS][Player]: Failed to extract signature decipher function. Oct 11 14:49:14 volumiofloersbach volumio[1349]: [YOUTUBEJS][Player]: Failed to extract n decipher function. Oct 11 14:49:14 volumiofloersbach volumio[1349]: error: Search in plugin ytmusic timed out Oct 11 14:49:14 volumiofloersbach volumio[1349]: info: All search sources collected, pushing search results Oct 11 14:49:14 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 14:49:14 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 11 14:49:15 volumiofloersbach volumio[1349]: info: [jellyfin-poller] Polled http://192.168.1.12:8096: offline Oct 11 14:49:15 volumiofloersbach volumio[1349]: info: [ytmusic] Obtained session PO token using visitorData (expires in 43199 seconds) Oct 11 14:49:19 volumiofloersbach volumio[1349]: [YOUTUBEJS][Player]: Failed to extract signature decipher function. Oct 11 14:49:19 volumiofloersbach volumio[1349]: [YOUTUBEJS][Player]: Failed to extract n decipher function. Oct 11 14:49:19 volumiofloersbach volumio[1349]: info: [ytmusic] Going to refresh session PO token in 43099 seconds Oct 11 14:49:20 volumiofloersbach volumio[1349]: error: Failed search in plugin ytmusic: Error: Unable to resolve or reject the same promise twice Oct 11 14:49:25 volumiofloersbach go-librespot[1857]: time="2026-10-11T14:49:25+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Oct 11 14:49:25 volumiofloersbach volumio[1349]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Oct 11 14:49:25 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 14:49:25 volumiofloersbach volumio[1349]: Cannot find translation for source Jellyfin Oct 11 14:49:25 volumiofloersbach volumio[1349]: Cannot find translation for source YouTube Music Oct 11 14:49:25 volumiofloersbach volumio[1349]: info: Disabling plugin spop Oct 11 14:49:25 volumiofloersbach volumio[1349]: info: Done. Oct 11 14:49:25 volumiofloersbach sudo[26297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Oct 11 14:49:25 volumiofloersbach sudo[26297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:49:25 volumiofloersbach volumio[1349]: info: Connection to go-librespot Websocket closed Oct 11 14:49:25 volumiofloersbach systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Oct 11 14:49:25 volumiofloersbach systemd[1]: go-librespot-daemon.service: Deactivated successfully. Oct 11 14:49:25 volumiofloersbach systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:49:25 volumiofloersbach systemd[1]: go-librespot-daemon.service: Consumed 5.606s CPU time. Oct 11 14:49:25 volumiofloersbach 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. Oct 11 14:49:25 volumiofloersbach 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. Oct 11 14:49:25 volumiofloersbach 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. Oct 11 14:49:25 volumiofloersbach 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. Oct 11 14:49:25 volumiofloersbach sudo[26297]: pam_unix(sudo:session): session closed for user root Oct 11 14:49:27 volumiofloersbach volumio[1349]: info: Enabling plugin spop Oct 11 14:49:27 volumiofloersbach volumio[1349]: info: Loading plugin "spop"... Oct 11 14:49:27 volumiofloersbach volumio[1349]: info: PLUGIN START: spop Oct 11 14:49:28 volumiofloersbach volumio[1349]: info: Creating Spotify config file Oct 11 14:49:28 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 14:49:28 volumiofloersbach volumio[1349]: info: Done. Oct 11 14:49:28 volumiofloersbach volumio[1349]: info: Spotify config file written Oct 11 14:49:28 volumiofloersbach volumio[1349]: info: No need to fix Spotify hosts Oct 11 14:49:28 volumiofloersbach sudo[26318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 11 14:49:28 volumiofloersbach sudo[26318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:49:28 volumiofloersbach 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. Oct 11 14:49:28 volumiofloersbach 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. Oct 11 14:49:28 volumiofloersbach systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:49:28 volumiofloersbach go-librespot[26320]: go-librespot daemon starting... Oct 11 14:49:28 volumiofloersbach sudo[26318]: pam_unix(sudo:session): session closed for user root Oct 11 14:49:28 volumiofloersbach go-librespot[26321]: time="2026-10-11T14:49:28+02:00" level=info msg="running go-librespot 0.6.2" Oct 11 14:49:28 volumiofloersbach go-librespot[26321]: time="2026-10-11T14:49:28+02:00" level=debug msg="app state loaded" Oct 11 14:49:28 volumiofloersbach go-librespot[26321]: time="2026-10-11T14:49:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:49:28 volumiofloersbach volumio[1349]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 11 14:49:28 volumiofloersbach go-librespot[26321]: time="2026-10-11T14:49:28+02: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]" Oct 11 14:49:28 volumiofloersbach go-librespot[26321]: time="2026-10-11T14:49:28+02: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]" Oct 11 14:49:28 volumiofloersbach go-librespot[26321]: time="2026-10-11T14:49:28+02: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]" Oct 11 14:49:28 volumiofloersbach go-librespot[26321]: time="2026-10-11T14:49:28+02:00" level=info msg="zeroconf server listening on port 46031" Oct 11 14:49:29 volumiofloersbach volumio[1349]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 14:49:31 volumiofloersbach volumio[1349]: info: go-librespot daemon successfully initialized Oct 11 14:49:34 volumiofloersbach volumio[1349]: info: Initializing connection to go-librespot Websocket Oct 11 14:49:34 volumiofloersbach go-librespot[26321]: time="2026-10-11T14:49:34+02:00" level=debug msg="new websocket client" Oct 11 14:49:34 volumiofloersbach volumio[1349]: info: Connection to go-librespot Websocket established Oct 11 14:49:37 volumiofloersbach volumio[1349]: info: Getting Spotify volume Oct 11 14:49:37 volumiofloersbach volumio[1349]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 11 14:49:37 volumiofloersbach volumio[1349]: info: CoreCommandRouter::volumioGetState Oct 11 14:49:37 volumiofloersbach volumio[1349]: info: CorePlayQueue::getTrack 0 Oct 11 14:49:37 volumiofloersbach volumio[1349]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Oct 11 14:49:45 volumiofloersbach volumio[1349]: info: [jellyfin-poller] Polled http://192.168.1.12:8096: offline Oct 11 14:50:15 volumiofloersbach volumio[1349]: info: [jellyfin-poller] Polled http://192.168.1.12:8096: offline Oct 11 14:50:15 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:15.695+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s Oct 11 14:50:15 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:15.740+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=http://pushupdates.volumio.org duration=41.51143ms Oct 11 14:50:15 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:15.818+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=122.199266ms Oct 11 14:50:15 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:15.914+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=217.451087ms Oct 11 14:50:15 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:15.933+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=235.779169ms Oct 11 14:50:15 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:15.937+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=https://securetoken.googleapis.com duration=240.77047ms Oct 11 14:50:15 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:15.953+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=https://www.googleapis.com duration=256.045112ms Oct 11 14:50:15 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:15.991+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=https://functions.volumio.cloud duration=292.40739ms Oct 11 14:50:16 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:16.020+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=320.957146ms Oct 11 14:50:16 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:16.101+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=https://functions.volumio.cloud duration=403.234146ms Oct 11 14:50:16 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:16.154+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=https://database.volumio.cloud duration=456.53608ms Oct 11 14:50:16 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:16.279+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=https://google.com duration=583.148285ms Oct 11 14:50:16 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:16.677+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=http://cddb.volumio.org duration=980.274293ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 11 14:50:18 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:18.118+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%01,192.168.1.133:54798 @ 0x1db7da0" latency=4.790857ms timeout=10s endpoint=http://plugins.volumio.org duration=2.421334718s Oct 11 14:50:18 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 14:50:18 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 14:50:18 volumiofloersbach volumio[1349]: info: Discovery: Getting this device information Oct 11 14:50:18 volumiofloersbach volumio[1349]: info: CoreCommandRouter::volumioGetState Oct 11 14:50:18 volumiofloersbach volumio[1349]: info: CorePlayQueue::getTrack 0 Oct 11 14:50:18 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 14:50:18 volumiofloersbach volumio[1349]: verbose: New Socket.io Connection to 192.168.1.21:3000 from 192.168.1.133 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Oct 11 14:50:18 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 11 14:50:18 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: Received OAUTH Data Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: Executing Spotify Oauth Login Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: Saving Spotify Refresh Token Oct 11 14:50:31 volumiofloersbach sudo[26436]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 11 14:50:31 volumiofloersbach sudo[26436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:50:31 volumiofloersbach sudo[26436]: pam_unix(sudo:session): session closed for user root Oct 11 14:50:31 volumiofloersbach sudo[26438]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 11 14:50:31 volumiofloersbach sudo[26438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:50:31 volumiofloersbach sudo[26438]: pam_unix(sudo:session): session closed for user root Oct 11 14:50:31 volumiofloersbach volumio[1349]: verbose: New Socket.io Connection to 192.168.1.21 from 192.168.1.133 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 9 Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: New Spotify access tokenBQC75HmBMB... Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: CoreCommandRouter::volumioGetState Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: CorePlayQueue::getTrack 0 Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 11 14:50:31 volumiofloersbach volumio[1349]: SPOTIFY: User informations: {"account_id":"eMwoI48zO7","country":"DE","display_name":"Jörg Preger","email":"joerg@preger.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1193026073"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/1193026073","id":"1193026073","images":[{"height":300,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/764938187_27716286397981770_366882435507853847_n.jpg?stp=dst-jpg_s320x320_tt6&_nc_cat=107&ccb=1-7&_nc_sid=08baa4&_nc_ohc=dA8FH8OvfNcQ7kNvwF44l-f&_nc_oc=AdrgAzTxdOei8dRQ6pNPzqbUcQFbY4IKqQyEhR_BDSNjI0WDtme9MVnNWUIqrcHAwD-ldLBp6BCffexOZXBvZmHE&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=lMxZpIrrjpAxY1UoqexUCQ&_nc_tpa=Q5bMBQJOOwpy_8ZMz5XfGAbXBaOv4k3VsVxkeN5ze_eFAdPXrxjk2ZgKwwuu9_-LiT5YXrGAGDvh&oh=00_AQP_myrQ4FfE2IYpn30y_1CYGqQ_JzwodMepH5pA9i8j8A&oe=6AD0E214","width":300},{"height":64,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/764938187_27716286397981770_366882435507853847_n.jpg?stp=cp0_dst-jpg_s50x50_tt6&_nc_cat=107&ccb=1-7&_nc_sid=28885b&_nc_ohc=dA8FH8OvfNcQ7kNvwF44l-f&_nc_oc=AdrgAzTxdOei8dRQ6pNPzqbUcQFbY4IKqQyEhR_BDSNjI0WDtme9MVnNWUIqrcHAwD-ldLBp6BCffexOZXBvZmHE&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=lMxZpIrrjpAxY1UoqexUCQ&_nc_tpa=Q5bMBQK1jm6qIsC3uWg0R_omz0N2OPsNh5pCR7AR2vfCKSEHiTCZjHuVlUsasDMdtd8bedcEAda8&oh=00_AQNBfY1fdpyNKup0Zj9vZK6tam3PuAwcyfNeqLRCDWQXoQ&oe=6AD0E214","width":64}],"product":"premium","type":"user","uri":"spotify:user:1193026073"} Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: Creating Spotify config file Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: Spotify config file written Oct 11 14:50:31 volumiofloersbach sudo[26443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 11 14:50:31 volumiofloersbach sudo[26443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:50:31 volumiofloersbach systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Oct 11 14:50:31 volumiofloersbach systemd[1]: go-librespot-daemon.service: Deactivated successfully. Oct 11 14:50:31 volumiofloersbach systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:50:31 volumiofloersbach volumio[1349]: info: Connection to go-librespot Websocket closed Oct 11 14:50:32 volumiofloersbach systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:50:32 volumiofloersbach go-librespot[26445]: go-librespot daemon starting... Oct 11 14:50:32 volumiofloersbach sudo[26443]: pam_unix(sudo:session): session closed for user root Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02:00" level=info msg="running go-librespot 0.6.2" Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02:00" level=debug msg="app state loaded" Oct 11 14:50:32 volumiofloersbach volumio[1349]: info: New Spotify access tokenBQAekkypm9... Oct 11 14:50:32 volumiofloersbach volumio[1349]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:50:32 volumiofloersbach volumio[1349]: SPOTIFY: User informations: {"account_id":"eMwoI48zO7","country":"DE","display_name":"Jörg Preger","email":"joerg@preger.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1193026073"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/1193026073","id":"1193026073","images":[{"height":300,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/764938187_27716286397981770_366882435507853847_n.jpg?stp=dst-jpg_s320x320_tt6&_nc_cat=107&ccb=1-7&_nc_sid=08baa4&_nc_ohc=dA8FH8OvfNcQ7kNvwF44l-f&_nc_oc=AdrgAzTxdOei8dRQ6pNPzqbUcQFbY4IKqQyEhR_BDSNjI0WDtme9MVnNWUIqrcHAwD-ldLBp6BCffexOZXBvZmHE&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=lMxZpIrrjpAxY1UoqexUCQ&_nc_tpa=Q5bMBQJOOwpy_8ZMz5XfGAbXBaOv4k3VsVxkeN5ze_eFAdPXrxjk2ZgKwwuu9_-LiT5YXrGAGDvh&oh=00_AQP_myrQ4FfE2IYpn30y_1CYGqQ_JzwodMepH5pA9i8j8A&oe=6AD0E214","width":300},{"height":64,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t39.30808-1/764938187_27716286397981770_366882435507853847_n.jpg?stp=cp0_dst-jpg_s50x50_tt6&_nc_cat=107&ccb=1-7&_nc_sid=28885b&_nc_ohc=dA8FH8OvfNcQ7kNvwF44l-f&_nc_oc=AdrgAzTxdOei8dRQ6pNPzqbUcQFbY4IKqQyEhR_BDSNjI0WDtme9MVnNWUIqrcHAwD-ldLBp6BCffexOZXBvZmHE&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=lMxZpIrrjpAxY1UoqexUCQ&_nc_tpa=Q5bMBQK1jm6qIsC3uWg0R_omz0N2OPsNh5pCR7AR2vfCKSEHiTCZjHuVlUsasDMdtd8bedcEAda8&oh=00_AQNBfY1fdpyNKup0Zj9vZK6tam3PuAwcyfNeqLRCDWQXoQ&oe=6AD0E214","width":64}],"product":"premium","type":"user","uri":"spotify:user:1193026073"} Oct 11 14:50:32 volumiofloersbach volumio[1349]: info: Spotify Successfully logged in Oct 11 14:50:32 volumiofloersbach volumio[1349]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 11 14:50:32 volumiofloersbach volumio[1349]: info: [1791723032242] CoreMusicLibrary::Adding element Spotify Oct 11 14:50:32 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 14:50:32 volumiofloersbach volumio[1349]: Cannot find translation for source Jellyfin Oct 11 14:50:32 volumiofloersbach volumio[1349]: Cannot find translation for source YouTube Music Oct 11 14:50:32 volumiofloersbach volumio[1349]: Cannot find translation for source Spotify Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02: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]" Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02: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]" Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02: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]" Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02:00" level=info msg="zeroconf server listening on port 39173" Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02:00" level=debug msg="obtained new client token: AAFQ9JjC+OUJrHn1KaM40ZZYf+ESxHT+XjKELdhl5NHZVtwTtxe075+R3OFbATvhxOB0gjRE8O1FQyqocNw39PAayMlQIg1Rfmjb0YqsiRC4jj0gHKCSQGWarbfEqEZFSm9R0P0mD8VyVTDMRISaxjjlG9+xxoJ9Hu0UQk/yWPGMyYeIz+NjJklPtCgWLvEp+Le7MX+ID4n+loi0Te/eA2hJVCMhGJT/chj19CWnB/w+1lAa2v1nDeS7iw==" Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02:00" level=debug msg="completed keyexchange" Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02:00" level=debug msg="completed challenge" Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02:00" level=info msg="authenticated AP" username="11******73" Oct 11 14:50:32 volumiofloersbach go-librespot[26446]: time="2026-10-11T14:50:32+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:50:32 volumiofloersbach systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:50:32 volumiofloersbach systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:50:33 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 14:50:33 volumiofloersbach volumio[1349]: info: Received Get System Info Oct 11 14:50:33 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 14:50:33 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 14:50:33 volumiofloersbach volumio[1349]: info: Discovery: Getting this device information Oct 11 14:50:33 volumiofloersbach volumio[1349]: info: CoreCommandRouter::volumioGetState Oct 11 14:50:33 volumiofloersbach volumio[1349]: info: CorePlayQueue::getTrack 0 Oct 11 14:50:33 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 14:50:34 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 14:50:34 volumiofloersbach volumio[1349]: info: Received Get System Info Oct 11 14:50:34 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 14:50:34 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 14:50:34 volumiofloersbach volumio[1349]: info: Discovery: Getting this device information Oct 11 14:50:34 volumiofloersbach volumio[1349]: info: CoreCommandRouter::volumioGetState Oct 11 14:50:34 volumiofloersbach volumio[1349]: info: CorePlayQueue::getTrack 0 Oct 11 14:50:34 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 14:50:34 volumiofloersbach volumio[1349]: info: Initializing connection to go-librespot Websocket Oct 11 14:50:34 volumiofloersbach volumio[1349]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:50:35 volumiofloersbach volumio[1349]: info: go-librespot daemon successfully initialized Oct 11 14:50:36 volumiofloersbach systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Oct 11 14:50:36 volumiofloersbach systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:50:36 volumiofloersbach systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:50:36 volumiofloersbach go-librespot[26456]: go-librespot daemon starting... Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02:00" level=info msg="running go-librespot 0.6.2" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02:00" level=debug msg="app state loaded" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02: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]" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02: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]" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02: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]" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02:00" level=info msg="zeroconf server listening on port 40283" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02:00" level=debug msg="obtained new client token: AAHZcfwxqdf4cVORxu5VT0K/Y+Mr4J2SVIr2OLU0eraF581RRxRQcjtRU//9Xefwlpwi8HvImTkuIoWU1LaTm5Y/hTO4Uv8OmfNx42R6dcq/pgp6Q07+eUcL3Kd7Ukcu0alTmuofbl9ShL4oYmKupPZgEWomeqnnZtmVbZ0JMPzBYjqgWIPgMEw45waaza7spdZB1YkpcBjrvFuaKOeqK/Op0L+8xUaZ127xg9CogFiaGZxUVAiac1w0dw==" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02: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" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02:00" level=debug msg="completed keyexchange" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02:00" level=debug msg="completed challenge" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02:00" level=info msg="authenticated AP" username="11******73" Oct 11 14:50:36 volumiofloersbach go-librespot[26457]: time="2026-10-11T14:50:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:50:36 volumiofloersbach systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:50:36 volumiofloersbach systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:50:37 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:37.915+02:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.1.152:54355 error="read tcp 192.168.1.21:7331->192.168.1.152:54355: read: connection timed out" Oct 11 14:50:37 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:37.915+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.1.152:54355 Oct 11 14:50:37 volumiofloersbach volumio5-onboarding[1700]: time=2026-10-11T14:50:37.916+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.1.152:54355 Oct 11 14:50:37 volumiofloersbach volumio[1349]: info: Initializing connection to go-librespot Websocket Oct 11 14:50:37 volumiofloersbach volumio[1349]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:50:38 volumiofloersbach volumio[1349]: info: Initializing connection to go-librespot Websocket Oct 11 14:50:38 volumiofloersbach volumio[1349]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:50:39 volumiofloersbach systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Oct 11 14:50:39 volumiofloersbach systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:50:39 volumiofloersbach systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:50:39 volumiofloersbach go-librespot[26480]: go-librespot daemon starting... Oct 11 14:50:39 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:39+02:00" level=info msg="running go-librespot 0.6.2" Oct 11 14:50:39 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:39+02:00" level=debug msg="app state loaded" Oct 11 14:50:39 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:50:40 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:40+02: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]" Oct 11 14:50:40 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:40+02: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]" Oct 11 14:50:40 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:40+02: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]" Oct 11 14:50:40 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:40+02:00" level=info msg="zeroconf server listening on port 36615" Oct 11 14:50:40 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:40+02:00" level=debug msg="obtained new client token: AAH2GNGILaGtGWKq020FJjsBiBw+QQz/Zij7lTUv7s3AGCHv+h/ajRLu6wXtQQpmNCh9323dt6eTiAAENqPpIZ82+DYiSRlU+yC50rLFspjXb/vgf1wxaX3DzRJf2k6S+Nx3+T2/vfBv95RtDIPMrm0qFFRD7bE01ys8KyrZnvwkKj765Yt8kDnJHeunjC7un+xfgL8iRj239mE0xv269EXc7bHg2WN+vb01GKX4UhfzO0BPeZT9PV8=" Oct 11 14:50:40 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:50:40 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:40+02:00" level=debug msg="completed keyexchange" Oct 11 14:50:40 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:40+02:00" level=debug msg="completed challenge" Oct 11 14:50:40 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:40+02:00" level=info msg="authenticated AP" username="11******73" Oct 11 14:50:40 volumiofloersbach go-librespot[26481]: time="2026-10-11T14:50:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:50:40 volumiofloersbach systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:50:40 volumiofloersbach systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:50:41 volumiofloersbach volumio[1349]: info: Initializing connection to go-librespot Websocket Oct 11 14:50:41 volumiofloersbach volumio[1349]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:50:43 volumiofloersbach systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Oct 11 14:50:43 volumiofloersbach systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:50:43 volumiofloersbach systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:50:43 volumiofloersbach go-librespot[26494]: go-librespot daemon starting... Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02:00" level=info msg="running go-librespot 0.6.2" Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02:00" level=debug msg="app state loaded" Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02: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]" Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02: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]" Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02: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]" Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02:00" level=info msg="zeroconf server listening on port 33195" Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02:00" level=debug msg="obtained new client token: AAGpuwEk3q1RaS0UyLtbUaRg+9PnDeouDHSqBsY7X0nFSPmEIhMzau9Hz7qVKEREFnNAXhDkML8rcjctedeXSHikD/QrQn1lEU1+MyUN2z1V1QYtrbYFcCVSqZKVceEdkXCq0CD3jakdbc1ct7bFx2txXUrUok6fIQvMiMKYNOqPiW6TDY/IZfRcinnhMca1eI83T9hIQc5WqjkY0/h9vSnH/AVH2ixKyzRgpFUSbgFw1RPgd5J8YFNqsw==" Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02:00" level=debug msg="completed keyexchange" Oct 11 14:50:43 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:43+02:00" level=debug msg="completed challenge" Oct 11 14:50:44 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:44+02:00" level=info msg="authenticated AP" username="11******73" Oct 11 14:50:44 volumiofloersbach volumio[1349]: info: Initializing connection to go-librespot Websocket Oct 11 14:50:44 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:44+02:00" level=debug msg="new websocket client" Oct 11 14:50:44 volumiofloersbach volumio[1349]: info: Connection to go-librespot Websocket established Oct 11 14:50:44 volumiofloersbach go-librespot[26495]: time="2026-10-11T14:50:44+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:50:44 volumiofloersbach systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:50:44 volumiofloersbach volumio[1349]: info: Connection to go-librespot Websocket closed Oct 11 14:50:44 volumiofloersbach systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:50:45 volumiofloersbach volumio[1349]: info: [jellyfin-poller] Polled http://192.168.1.12:8096: offline Oct 11 14:50:46 volumiofloersbach volumio[1349]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Oct 11 14:50:46 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Oct 11 14:50:46 volumiofloersbach volumio[1349]: info: Creating Spotify config file Oct 11 14:50:46 volumiofloersbach volumio[1349]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 14:50:46 volumiofloersbach volumio[1349]: info: Spotify config file written Oct 11 14:50:46 volumiofloersbach sudo[26505]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 11 14:50:46 volumiofloersbach sudo[26505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 14:50:46 volumiofloersbach systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:50:46 volumiofloersbach systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 11 14:50:46 volumiofloersbach go-librespot[26507]: go-librespot daemon starting... Oct 11 14:50:46 volumiofloersbach sudo[26505]: pam_unix(sudo:session): session closed for user root Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02:00" level=info msg="running go-librespot 0.6.2" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02:00" level=debug msg="app state loaded" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02: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]" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02: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]" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02: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]" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02:00" level=info msg="zeroconf server listening on port 43181" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02:00" level=debug msg="obtained new client token: AAHs8YKLdXDeoSuSuKY2Ocz4aA032xVSYMOy+OXQO0CfRbfpxyBvH6RFi4MFSFU4qisDSkbP433ITI1Qytsn3em6VgifMEZZVKAkPyLRfAdh4CEX0XHw0cGIJ0X/Q5yw92SAxk07TgkoKKIzSmJvk9yKDgEqj8LjS+1p+22SgiuoGL43k0OIRvI/M9fYZ+42YMXUHd/K54vfLEmtxGDmeFzYCitufVVDHrudcdMf/mTdyqSpPK5yAYer/A==" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02:00" level=debug msg="completed keyexchange" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02:00" level=debug msg="completed challenge" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02:00" level=info msg="authenticated AP" username="11******73" Oct 11 14:50:46 volumiofloersbach go-librespot[26508]: time="2026-10-11T14:50:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 11 14:50:46 volumiofloersbach systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 11 14:50:46 volumiofloersbach systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 11 14:50:47 volumiofloersbach volumio[1349]: info: Getting Spotify volume Oct 11 14:50:47 volumiofloersbach volumio[1349]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 14:50:47 volumiofloersbach volumio[1349]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 11 14:50:47 volumiofloersbach volumio[1349]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 11 14:50:47 volumiofloersbach volumio[1349]: errno: -111, Oct 11 14:50:47 volumiofloersbach volumio[1349]: code: 'ECONNREFUSED', Oct 11 14:50:47 volumiofloersbach volumio[1349]: syscall: 'connect', Oct 11 14:50:47 volumiofloersbach volumio[1349]: address: '127.0.0.1', Oct 11 14:50:47 volumiofloersbach volumio[1349]: port: 9879, Oct 11 14:50:47 volumiofloersbach volumio[1349]: response: undefined Oct 11 14:50:47 volumiofloersbach volumio[1349]: } Oct 11 14:50:47 volumiofloersbach volumio[1349]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 14:50:47 volumiofloersbach sudo[26545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-11 14:49' Oct 11 14:50:47 volumiofloersbach sudo[26545]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"