Aug 29 17:15:00 kitchen volumio[10125]: info: Enabling plugin spop Aug 29 17:15:00 kitchen volumio[10125]: info: Loading plugin "spop"... Aug 29 17:15:01 kitchen volumio[10125]: info: PLUGIN START: spop Aug 29 17:15:01 kitchen volumio[10125]: info: Creating Spotify config file Aug 29 17:15:01 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 17:15:01 kitchen volumio[10125]: info: Done. Aug 29 17:15:01 kitchen volumio[10125]: info: Spotify config file written Aug 29 17:15:01 kitchen volumio[10125]: info: No need to fix Spotify hosts Aug 29 17:15:01 kitchen sudo[9720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 17:15:01 kitchen sudo[9720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 17:15:01 kitchen 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. Aug 29 17:15:01 kitchen 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. Aug 29 17:15:01 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:01 kitchen sudo[9720]: pam_unix(sudo:session): session closed for user root Aug 29 17:15:01 kitchen go-librespot[9722]: go-librespot daemon starting... Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=debug msg="app state loaded" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:01 kitchen volumio[10125]: info: New Spotify access tokenBQDl18NLa_... Aug 29 17:15:01 kitchen volumio[10125]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+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]" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+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]" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+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]" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=info msg="zeroconf server listening on port 34295" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:01 kitchen volumio[10125]: SPOTIFY: User informations: {"account_id":"nMg3wBFl41","country":"DK","display_name":"113304117","email":"johansen.henrik@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/113304117"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/113304117","id":"113304117","images":[],"product":"premium","type":"user","uri":"spotify:user:113304117"} Aug 29 17:15:01 kitchen volumio[10125]: info: Spotify Successfully logged in Aug 29 17:15:01 kitchen volumio[10125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 17:15:01 kitchen volumio[10125]: info: [1788016501410] CoreMusicLibrary::Adding element Spotify Aug 29 17:15:01 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 17:15:01 kitchen volumio[10125]: Cannot find translation for source Spotify Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=debug msg="obtained new client token: AAH5GSnHMBkO+tyZD80yhhFAAZaDnLM5m5sSrFbGgSLYMEbGXEM5TLvgiQKCdUtBAsembf7kAToLoP9fBiBV4Hr9ECUmAOnY9o3yXQHHew5KyNO3CJJFsO7aA336TznEWdbLDNc2BMVLdTnTHhWbtQV+HEZ2Z7Uqx3ieFswguk9SPYy0BNlwE+5Uv3UuBhL/svYSGDdo/g4VGzFJiqOR49f/sMX+drZx0DGdRNnHGtgv34G0VpRNT10=" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=debug msg="completed challenge" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:01 kitchen go-librespot[9723]: time="2026-08-29T17:15:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:01 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:01 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:04 kitchen volumio[10125]: info: go-librespot daemon successfully initialized Aug 29 17:15:04 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 17:15:04 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:05 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:05 kitchen go-librespot[9733]: go-librespot daemon starting... Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=debug msg="app state loaded" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+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]" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+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]" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+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]" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=info msg="zeroconf server listening on port 37027" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=debug msg="obtained new client token: AAEO+JfMo2Dq96LPl57O0ubLHhlZB4aiVYn/zYI7IJ13Dh4fumsEd/DSrf8rXo9VQ7UeT/bJ9cEssNnou3qjtREAWnmLzubZvblDQUBqVnG7JBbGEnzIGcxytKLGkFujPnZ9nAR7fkqfdMvBlqs76EhcsOFAGFBvWCt9q0IJnZuAMEdiJUUQCP+rqCZxBS6S8ZeKHPgc9kWCN+njsR6OJBjhbaOYrQzr0253R6yl9ZmwOZ0QNTESbWE=" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=debug msg="completed challenge" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:05 kitchen go-librespot[9734]: time="2026-08-29T17:15:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:05 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:05 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:07 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:07 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:08 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 17:15:08 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:08 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:08 kitchen go-librespot[9743]: go-librespot daemon starting... Aug 29 17:15:08 kitchen go-librespot[9744]: time="2026-08-29T17:15:08+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:08 kitchen go-librespot[9744]: time="2026-08-29T17:15:08+02:00" level=debug msg="app state loaded" Aug 29 17:15:08 kitchen go-librespot[9744]: time="2026-08-29T17:15:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:08 kitchen go-librespot[9744]: time="2026-08-29T17:15:08+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]" Aug 29 17:15:08 kitchen go-librespot[9744]: time="2026-08-29T17:15:08+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]" Aug 29 17:15:08 kitchen go-librespot[9744]: time="2026-08-29T17:15:08+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]" Aug 29 17:15:08 kitchen go-librespot[9744]: time="2026-08-29T17:15:08+02:00" level=info msg="zeroconf server listening on port 39655" Aug 29 17:15:08 kitchen go-librespot[9744]: time="2026-08-29T17:15:08+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:09 kitchen go-librespot[9744]: time="2026-08-29T17:15:09+02:00" level=debug msg="obtained new client token: AAF7DXzD3sDS1AcY/I+DRB16vo+hvc0qjhOFhEC/1BWpt5RA/1EWOsbyJrJY1NDhCftm5lUnWPD7qfrxS/8SVY74nJ9ferLMR1hqORp/pmaN8dbYAIbhKfsntMDAxAkc4i4h7WE7qU0mMtp/S8dBbjMR3eIifI6lKTpaoQvtFa0zEOdcbkQU+zqOXUXmG52WnjDP4yvI0i9LRewkzEbDHmGth5ANBw+J/GNmE+Rf7zMOOwxupb/J" Aug 29 17:15:09 kitchen go-librespot[9744]: time="2026-08-29T17:15:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:09 kitchen go-librespot[9744]: time="2026-08-29T17:15:09+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:09 kitchen go-librespot[9744]: time="2026-08-29T17:15:09+02:00" level=debug msg="completed challenge" Aug 29 17:15:09 kitchen go-librespot[9744]: time="2026-08-29T17:15:09+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:09 kitchen go-librespot[9744]: time="2026-08-29T17:15:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:09 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:09 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:10 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:10 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:12 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 29 17:15:12 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:12 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:12 kitchen go-librespot[9767]: go-librespot daemon starting... Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+02:00" level=debug msg="app state loaded" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+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]" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+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]" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+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]" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+02:00" level=info msg="zeroconf server listening on port 34897" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+02:00" level=debug msg="obtained new client token: AAEoF65F9aoItUF091n2WMw3a0X9ydt0N7o4KAH1PNjAzsLvE7iPuGek/Rawg7IX/FAbVvvV3rKEQw8HSBBurwx6WfWiuZttN5tX7eeAnt9YTkcaNYcO9+O+xiJEtLgHY2Qq5iwZLoPL8lNvBEqc3jnDTZ2dgPuSKQaibs5sssdgE296FxSW4F71/31v55oQF5My8O0kWNHXXQQ/9jmm/v2lpnthJDEM/od+M2jBNsNSqRgwcC1krtk=" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+02:00" level=debug msg="completed challenge" Aug 29 17:15:12 kitchen go-librespot[9768]: time="2026-08-29T17:15:12+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:13 kitchen go-librespot[9768]: time="2026-08-29T17:15:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:13 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:13 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:13 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:13 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:16 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:16 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:16 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 29 17:15:16 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:16 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:16 kitchen go-librespot[9777]: go-librespot daemon starting... Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=debug msg="app state loaded" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02: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]" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02: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]" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=info msg="zeroconf server listening on port 33401" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=debug msg="obtained new client token: AAGSy/4PH0bs0zSaGde3pIUUUg5IYtk5u/w7dmS1hkyxHnx1FxjLTDMUd2lLXYy68ZXqzOu4NY+G+1cvgCUu1YMDQ074Y/YEI9e7S2t6yD5wX8TFGtPSDpzZtz0FTOZb6NTLv7Gpmhffr2AB0bAPYK0v2stoh3dBUMBeprbUCgy5FfJe9mHv59x4VJsFT98yqwAnReG3WnpWjnDa33pOZmMeap4RkCn+ancwiSqpex9wzk4oXo2PrgY=" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=debug msg="completed challenge" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:16 kitchen go-librespot[9778]: time="2026-08-29T17:15:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:16 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:16 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:19 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:19 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:19 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 29 17:15:19 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:20 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:20 kitchen go-librespot[9801]: go-librespot daemon starting... Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=debug msg="app state loaded" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02: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]" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02: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]" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=info msg="zeroconf server listening on port 44771" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=debug msg="obtained new client token: AAHZxVdMdnPlwp4UKBIjY5skOVLw1UWZMKdHpWPwbmSk8vo5qAWrDvYXjg+65ErDxwWJSb0tXvNUNZyYWANDKGN2v7PrRac/ErlGQbtI4nYH7jUeF8jSjc9V172GyLEOKMBJ6kYk71K3H/CLPg5DWnZJ1o23aNTZt50KTIRL/+WNgBu6G0k8g3nTIMe4Mtlri8QYh3Baf1dIi+2S/23onTLWe7dYPvKV0AQUFPTNUnuC20NtvnnpE7M=" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=debug msg="completed challenge" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:20 kitchen go-librespot[9802]: time="2026-08-29T17:15:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:20 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:20 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:22 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:22 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:23 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 29 17:15:23 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:23 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:23 kitchen go-librespot[9811]: go-librespot daemon starting... Aug 29 17:15:23 kitchen go-librespot[9812]: time="2026-08-29T17:15:23+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:23 kitchen go-librespot[9812]: time="2026-08-29T17:15:23+02:00" level=debug msg="app state loaded" Aug 29 17:15:23 kitchen go-librespot[9812]: time="2026-08-29T17:15:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:23 kitchen go-librespot[9812]: time="2026-08-29T17:15:23+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 17:15:23 kitchen go-librespot[9812]: time="2026-08-29T17:15:23+02: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]" Aug 29 17:15:23 kitchen go-librespot[9812]: time="2026-08-29T17:15:23+02: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]" Aug 29 17:15:23 kitchen go-librespot[9812]: time="2026-08-29T17:15:23+02:00" level=info msg="zeroconf server listening on port 41113" Aug 29 17:15:23 kitchen go-librespot[9812]: time="2026-08-29T17:15:23+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:24 kitchen go-librespot[9812]: time="2026-08-29T17:15:24+02:00" level=debug msg="obtained new client token: AAET0XnaEkwrCfSqlBfIKnue27tuxANBCvwwz2AS/j7OOaM6SkNA1z1jW9mR2o5sd7eFjo326STBSY1czEvLn3y2VZzpEIPldtqcLsxK/nAEOLYw4gQYOKBjk6uuVjlTn7RSIY++7JmtuRxHzTLhvaSmaIB01MV9qmXcAdeoAJGIVADTMsKd92wcLEbGSEZzLyy6OkTAZ5N200UVINMX3jy0u4noEC66vWglvlPIr+GH4MQKKRg1" Aug 29 17:15:24 kitchen go-librespot[9812]: time="2026-08-29T17:15:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:24 kitchen go-librespot[9812]: time="2026-08-29T17:15:24+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:24 kitchen go-librespot[9812]: time="2026-08-29T17:15:24+02:00" level=debug msg="completed challenge" Aug 29 17:15:24 kitchen go-librespot[9812]: time="2026-08-29T17:15:24+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:24 kitchen go-librespot[9812]: time="2026-08-29T17:15:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:24 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:24 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:24 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:24.956+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s Aug 29 17:15:24 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:24.961+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=3.915818ms Aug 29 17:15:24 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:24.978+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=http://pushupdates.volumio.org duration=20.610863ms Aug 29 17:15:24 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:24.998+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=41.064263ms Aug 29 17:15:25 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:25.001+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=44.121046ms Aug 29 17:15:25 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:25.069+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=https://www.googleapis.com duration=112.445089ms Aug 29 17:15:25 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:25.119+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=https://functions.volumio.cloud duration=161.523819ms Aug 29 17:15:25 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:25.120+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=https://functions.volumio.cloud duration=162.420297ms Aug 29 17:15:25 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:25.121+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=https://securetoken.googleapis.com duration=164.172494ms Aug 29 17:15:25 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:25.121+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=164.208587ms Aug 29 17:15:25 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:25 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:25 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:25.177+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=https://google.com duration=220.620751ms Aug 29 17:15:25 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:25.308+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=https://database.volumio.cloud duration=349.502812ms Aug 29 17:15:25 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:25.509+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=http://plugins.volumio.org duration=550.85001ms Aug 29 17:15:25 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:25.629+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=82.880088ms timeout=10s endpoint=http://cddb.volumio.org duration=672.518451ms Aug 29 17:15:26 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 17:15:26 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 17:15:26 kitchen volumio[10125]: info: Discovery: Getting this device information Aug 29 17:15:26 kitchen volumio[10125]: info: CoreCommandRouter::volumioGetState Aug 29 17:15:26 kitchen volumio[10125]: info: CorePlayQueue::getTrack 0 Aug 29 17:15:26 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 17:15:26 kitchen volumio[10125]: verbose: New Socket.io Connection to 10.0.1.11:3000 from 10.0.1.107 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 29 17:15:26 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 17:15:26 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 17:15:27 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 29 17:15:27 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:27 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:27 kitchen go-librespot[9822]: go-librespot daemon starting... Aug 29 17:15:27 kitchen volumio[10125]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Aug 29 17:15:27 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 17:15:27 kitchen volumio[10125]: info: Disabling plugin spop Aug 29 17:15:27 kitchen volumio[10125]: info: Done. Aug 29 17:15:27 kitchen go-librespot[9823]: time="2026-08-29T17:15:27+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:27 kitchen go-librespot[9823]: time="2026-08-29T17:15:27+02:00" level=debug msg="app state loaded" Aug 29 17:15:27 kitchen sudo[9829]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Aug 29 17:15:27 kitchen sudo[9829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 17:15:27 kitchen go-librespot[9823]: time="2026-08-29T17:15:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:27 kitchen systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 29 17:15:27 kitchen systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 29 17:15:27 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:27 kitchen 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. Aug 29 17:15:27 kitchen 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. Aug 29 17:15:27 kitchen 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. Aug 29 17:15:27 kitchen 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. Aug 29 17:15:27 kitchen 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. Aug 29 17:15:27 kitchen 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. Aug 29 17:15:27 kitchen sudo[9829]: pam_unix(sudo:session): session closed for user root Aug 29 17:15:28 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:28 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:30 kitchen volumio[10125]: info: Enabling plugin spop Aug 29 17:15:30 kitchen volumio[10125]: info: Loading plugin "spop"... Aug 29 17:15:30 kitchen volumio[10125]: info: PLUGIN START: spop Aug 29 17:15:30 kitchen volumio[10125]: info: Creating Spotify config file Aug 29 17:15:30 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 17:15:30 kitchen volumio[10125]: info: Done. Aug 29 17:15:30 kitchen volumio[10125]: info: Spotify config file written Aug 29 17:15:30 kitchen volumio[10125]: info: No need to fix Spotify hosts Aug 29 17:15:30 kitchen sudo[9849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 17:15:30 kitchen sudo[9849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 17:15:30 kitchen 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. Aug 29 17:15:30 kitchen 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. Aug 29 17:15:30 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:30 kitchen go-librespot[9851]: go-librespot daemon starting... Aug 29 17:15:30 kitchen sudo[9849]: pam_unix(sudo:session): session closed for user root Aug 29 17:15:30 kitchen go-librespot[9852]: time="2026-08-29T17:15:30+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:30 kitchen go-librespot[9852]: time="2026-08-29T17:15:30+02:00" level=debug msg="app state loaded" Aug 29 17:15:30 kitchen go-librespot[9852]: time="2026-08-29T17:15:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:30 kitchen volumio[10125]: info: New Spotify access tokenBQDCW1vWK7... Aug 29 17:15:30 kitchen volumio[10125]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 17:15:31 kitchen volumio[10125]: SPOTIFY: User informations: {"account_id":"nMg3wBFl41","country":"DK","display_name":"113304117","email":"johansen.henrik@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/113304117"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/113304117","id":"113304117","images":[],"product":"premium","type":"user","uri":"spotify:user:113304117"} Aug 29 17:15:31 kitchen volumio[10125]: info: Spotify Successfully logged in Aug 29 17:15:31 kitchen volumio[10125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 17:15:31 kitchen volumio[10125]: info: [1788016531142] CoreMusicLibrary::Adding element Spotify Aug 29 17:15:31 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 17:15:31 kitchen volumio[10125]: Cannot find translation for source Spotify Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+02: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]" Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+02: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]" Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+02:00" level=info msg="zeroconf server listening on port 46703" Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+02:00" level=debug msg="obtained new client token: AAEuhqn3kPKai2gJnEA9Akf9RyeFALOVLwfMaSsgDx30zBqKOlwPONMFvFkCTUZSTQuaM5ppEDS5gpacQqYAX4yrTt7OAlgtrQCJrA+cFg0jaJ+TOrf6QxTaXgx1FOTX94N642LFJDCUJzjRXCjSBrkTyNcTQPjvxvC/nSNJZRdQ0aJaeN+VZcjGLm1fqtU4+ZHtP+ZR9aZbqn0B8l8LwNxHj8593dM4p1DNrRy3XEWlg+YOLgNv" Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+02:00" level=debug msg="completed challenge" Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:31 kitchen go-librespot[9852]: time="2026-08-29T17:15:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:31 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:31 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:32 kitchen volumio[10125]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 29 17:15:33 kitchen volumio[10125]: info: go-librespot daemon successfully initialized Aug 29 17:15:34 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 17:15:34 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:34 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:34 kitchen go-librespot[9862]: go-librespot daemon starting... Aug 29 17:15:34 kitchen go-librespot[9863]: time="2026-08-29T17:15:34+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:34 kitchen go-librespot[9863]: time="2026-08-29T17:15:34+02:00" level=debug msg="app state loaded" Aug 29 17:15:34 kitchen go-librespot[9863]: time="2026-08-29T17:15:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:34 kitchen go-librespot[9863]: time="2026-08-29T17:15:34+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 17:15:34 kitchen go-librespot[9863]: time="2026-08-29T17:15:34+02: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]" Aug 29 17:15:34 kitchen go-librespot[9863]: time="2026-08-29T17:15:34+02: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]" Aug 29 17:15:34 kitchen go-librespot[9863]: time="2026-08-29T17:15:34+02:00" level=info msg="zeroconf server listening on port 42825" Aug 29 17:15:34 kitchen go-librespot[9863]: time="2026-08-29T17:15:34+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:35 kitchen go-librespot[9863]: time="2026-08-29T17:15:35+02:00" level=debug msg="obtained new client token: AAGJtEa+ApdHp+0HyTFjmbP4ITUEQY+fzsxWUWgb0qL7eNMW8Kl6iiXalLByFYwNykpMgHLf9udQ/vCiPs7ltBDq2gHclCWwWauELIBrvW7W7HmGvjK3eIZsZCa/DH9CahwAEXkc/aJkYJA6BTrva6Vq+Wf2xT2JlPol9ULpwtN02d4Ov/yNfmwEMYcLoak2PRm/s+SgdPfcMdBQLDaDmODECFFLmLkKGzZI5pdP0g2VcbT8Wp19" Aug 29 17:15:35 kitchen go-librespot[9863]: time="2026-08-29T17:15:35+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:35 kitchen go-librespot[9863]: time="2026-08-29T17:15:35+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:35 kitchen go-librespot[9863]: time="2026-08-29T17:15:35+02:00" level=debug msg="completed challenge" Aug 29 17:15:35 kitchen go-librespot[9863]: time="2026-08-29T17:15:35+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:35 kitchen go-librespot[9863]: time="2026-08-29T17:15:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:35 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:35 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:36 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:36 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:38 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 17:15:38 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:38 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:38 kitchen go-librespot[9872]: go-librespot daemon starting... Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+02:00" level=debug msg="app state loaded" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+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]" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+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]" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+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]" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+02:00" level=info msg="zeroconf server listening on port 38189" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+02:00" level=debug msg="obtained new client token: AAHrjwqDRg03SnZRLyUX8A2oTZ23T3pV4gZI2huxLntQigQARA5vcAur+ZsqkZUF+537qcje74xvdznTOaHIwfDPlPUR5RFPwpLRSpgulhMITO1lxs3YXhSme2sHOmQMXnZLC/Jbx/sR103NFSBDZZZW0FEIQBgeRKBsIVt4rbpqgKD9HlWxqi2YzQ7ODRoO5nQ3ccxEcWNJ2VQiCW3sQeoD5cxGTzG+b2pbISJ4ABL31QApLnKiiso=" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+02:00" level=debug msg="completed challenge" Aug 29 17:15:38 kitchen go-librespot[9873]: time="2026-08-29T17:15:38+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:39 kitchen go-librespot[9873]: time="2026-08-29T17:15:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:39 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:39 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:39 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:39 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:42 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 29 17:15:42 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:42 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:42 kitchen go-librespot[9896]: go-librespot daemon starting... Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=debug msg="app state loaded" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02: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]" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02: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]" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=info msg="zeroconf server listening on port 32941" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=debug msg="obtained new client token: AAFC/+Y7rXUQn8bvuyWCDEcoReFO7mqNlG6eyaIfOTQj2EcTQzoFIfGwLfiKZMB6JiJbzq/ptERAXjaagGORTF23b/qiUTm3LdxzI4sxmEgYIEd/sk7kcf44esgG/yQipnLora2CbsvILpvl8mXw9FJ32l4HXcvNDmntCciHHnMa8EyeHVduElwFqTeKXDd0e90Lho1iBS/t4vlKOLX2pp4mKdX2E693NHXLKTz7bG4FQ5/X7Jb2gnM=" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=debug msg="completed challenge" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:42 kitchen go-librespot[9897]: time="2026-08-29T17:15:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:42 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:42 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:42 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:42 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:45 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:45.896+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s Aug 29 17:15:45 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:45.900+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=3.751151ms Aug 29 17:15:45 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:45.919+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=http://pushupdates.volumio.org duration=21.003361ms Aug 29 17:15:45 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 17:15:45 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 17:15:45 kitchen volumio[10125]: info: Discovery: Getting this device information Aug 29 17:15:45 kitchen volumio[10125]: info: CoreCommandRouter::volumioGetState Aug 29 17:15:45 kitchen volumio[10125]: info: CorePlayQueue::getTrack 0 Aug 29 17:15:45 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 17:15:45 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:45.940+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=41.518464ms Aug 29 17:15:45 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:45.942+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=43.751789ms Aug 29 17:15:45 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:45 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:45 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 29 17:15:45 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:45 kitchen volumio[10125]: verbose: New Socket.io Connection to 10.0.1.11:3000 from 10.0.1.107 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Aug 29 17:15:45 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 17:15:45 kitchen volumio[10125]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 17:15:46 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:46.013+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=https://www.googleapis.com duration=115.473614ms Aug 29 17:15:46 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:46 kitchen go-librespot[9907]: go-librespot daemon starting... Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=debug msg="app state loaded" Aug 29 17:15:46 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:46.051+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=https://securetoken.googleapis.com duration=153.442037ms Aug 29 17:15:46 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:46.057+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=159.003126ms Aug 29 17:15:46 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:46.058+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=https://functions.volumio.cloud duration=160.7126ms Aug 29 17:15:46 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:46.058+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=https://functions.volumio.cloud duration=159.930104ms Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:46 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:46.066+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=https://database.volumio.cloud duration=168.03483ms Aug 29 17:15:46 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:46.139+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=https://google.com duration=242.364275ms Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02: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]" Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02: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]" Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=info msg="zeroconf server listening on port 44799" Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:46 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:46.344+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=http://cddb.volumio.org duration=446.849925ms Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=debug msg="obtained new client token: AAFx828NsIIPcsB4bjnOnDYFcKPnF8PWyX+d6xKr7rhYanZ3rJ7ScUUQUgs8B7BeR71gARXTSLxtXLAnLndq58AAP+VNYuhJC+nLZc9GtHNNYCAls0sTEIK3TNSsPGw+bb2trYwS+SGycv7gZtw3kMzMIZY95GHVXWUXiLrx3NUW8F32NnmDQuydUG/flugDvUrvuO6az12EvfliER0kaM+A0HufTDipwVSZSt5/7KXsTBIQuLmofFI=" Aug 29 17:15:46 kitchen volumio5-onboarding[1766]: time=2026-08-29T17:15:46.425+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.1.107:39084,00:00:00:00:00:00%03 @ 0x1800090" latency=85.695628ms timeout=10s endpoint=http://plugins.volumio.org duration=527.210142ms Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=debug msg="completed challenge" Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:46 kitchen go-librespot[9908]: time="2026-08-29T17:15:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:46 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:46 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:48 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:48 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:49 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 29 17:15:49 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:49 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:49 kitchen go-librespot[9918]: go-librespot daemon starting... Aug 29 17:15:49 kitchen go-librespot[9919]: time="2026-08-29T17:15:49+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:49 kitchen go-librespot[9919]: time="2026-08-29T17:15:49+02:00" level=debug msg="app state loaded" Aug 29 17:15:49 kitchen go-librespot[9919]: time="2026-08-29T17:15:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:49 kitchen go-librespot[9919]: time="2026-08-29T17:15:49+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]" Aug 29 17:15:49 kitchen go-librespot[9919]: time="2026-08-29T17:15:49+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]" Aug 29 17:15:49 kitchen go-librespot[9919]: time="2026-08-29T17:15:49+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]" Aug 29 17:15:49 kitchen go-librespot[9919]: time="2026-08-29T17:15:49+02:00" level=info msg="zeroconf server listening on port 34295" Aug 29 17:15:49 kitchen go-librespot[9919]: time="2026-08-29T17:15:49+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:50 kitchen go-librespot[9919]: time="2026-08-29T17:15:50+02:00" level=debug msg="obtained new client token: AAHQ/QX8cjcVe+qsNsdEVrjENbfcULxdvDsExHAfX6D6nclE3YUsKZK2uhkyp/FNZc8adnimEhOZEZR46HVRQeHK11da7WJ6o0SAaqBPKyNZwdfNFwcc96evJMLFypWjZK/2iGjIO7CZy6G3vQtOx1IysV7h4dNN4T2YtzVCs03hkVETHuHdnmrWV1tgTgzay5H9/SR/S/2P349Y+aCbUtGRy/1dBT00agVI9/JKp+SH/uAOTmOX" Aug 29 17:15:50 kitchen go-librespot[9919]: time="2026-08-29T17:15:50+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" Aug 29 17:15:50 kitchen go-librespot[9919]: time="2026-08-29T17:15:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 29 17:15:50 kitchen go-librespot[9919]: time="2026-08-29T17:15:50+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:50 kitchen go-librespot[9919]: time="2026-08-29T17:15:50+02:00" level=debug msg="completed challenge" Aug 29 17:15:50 kitchen go-librespot[9919]: time="2026-08-29T17:15:50+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:50 kitchen go-librespot[9919]: time="2026-08-29T17:15:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:50 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:50 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:50 kitchen volumio[10125]: info: CoreCommandRouter::volumioPlay Aug 29 17:15:50 kitchen volumio[10125]: info: CoreStateMachine::play index undefined Aug 29 17:15:50 kitchen volumio[10125]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:15:50 kitchen volumio[10125]: info: CorePlayQueue::getTrack 0 Aug 29 17:15:50 kitchen volumio[10125]: info: CoreStateMachine::startPlaybackTimer Aug 29 17:15:50 kitchen volumio[10125]: info: CorePlayQueue::getTrack 0 Aug 29 17:15:50 kitchen volumio[10125]: info: [1788016550881] ControllerSpotify::clearAddPlayTrack Aug 29 17:15:50 kitchen volumio[10125]: info: Sending Spotify command with payload to local API: /player/play Aug 29 17:15:50 kitchen volumio[10125]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:51 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:51 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:52 kitchen volumio[10125]: info: CoreCommandRouter::volumioPlay Aug 29 17:15:52 kitchen volumio[10125]: info: CoreStateMachine::play index undefined Aug 29 17:15:52 kitchen volumio[10125]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:15:52 kitchen volumio[10125]: info: CorePlayQueue::getTrack 0 Aug 29 17:15:52 kitchen volumio[10125]: info: CoreStateMachine::startPlaybackTimer Aug 29 17:15:52 kitchen volumio[10125]: info: CorePlayQueue::getTrack 0 Aug 29 17:15:52 kitchen volumio[10125]: info: [1788016552967] ControllerSpotify::clearAddPlayTrack Aug 29 17:15:52 kitchen volumio[10125]: info: Sending Spotify command with payload to local API: /player/play Aug 29 17:15:52 kitchen volumio[10125]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:53 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 29 17:15:53 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:53 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:53 kitchen go-librespot[9943]: go-librespot daemon starting... Aug 29 17:15:53 kitchen go-librespot[9944]: time="2026-08-29T17:15:53+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:53 kitchen go-librespot[9944]: time="2026-08-29T17:15:53+02:00" level=debug msg="app state loaded" Aug 29 17:15:53 kitchen go-librespot[9944]: time="2026-08-29T17:15:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:53 kitchen go-librespot[9944]: time="2026-08-29T17:15:53+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 17:15:53 kitchen go-librespot[9944]: time="2026-08-29T17:15:53+02: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]" Aug 29 17:15:53 kitchen go-librespot[9944]: time="2026-08-29T17:15:53+02: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]" Aug 29 17:15:53 kitchen go-librespot[9944]: time="2026-08-29T17:15:53+02:00" level=info msg="zeroconf server listening on port 35303" Aug 29 17:15:53 kitchen go-librespot[9944]: time="2026-08-29T17:15:53+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:53 kitchen go-librespot[9944]: time="2026-08-29T17:15:53+02:00" level=debug msg="obtained new client token: AAG82sLCqVAb6nj9eoo3pFABRjezo8h0FO2RIW+yE59gGJrhMSLQw1QHjIOBrAJlOS98TWt3wGYPYNRyyZXtRqDsSpKvfiiQuVGmVjFOrw0nnxEQddL7fHyjDfwGsBaU9ZK9TFPwzZ7M/pa8Qto7OClAc9r2lkA3+CIe5mhsqxdpZ0Z5pATYht5K0+axtptkxdG45bN+D51QhiN9BOuE1fvZ3aR9rFW/6rh+B0whNfSNcb/b3IdtC2I=" Aug 29 17:15:53 kitchen go-librespot[9944]: time="2026-08-29T17:15:53+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:54 kitchen go-librespot[9944]: time="2026-08-29T17:15:54+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:54 kitchen go-librespot[9944]: time="2026-08-29T17:15:54+02:00" level=debug msg="completed challenge" Aug 29 17:15:54 kitchen go-librespot[9944]: time="2026-08-29T17:15:54+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:54 kitchen go-librespot[9944]: time="2026-08-29T17:15:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:54 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:54 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:15:54 kitchen volumio[10125]: info: CoreCommandRouter::volumioPlay Aug 29 17:15:54 kitchen volumio[10125]: info: CoreStateMachine::play index undefined Aug 29 17:15:54 kitchen volumio[10125]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 17:15:54 kitchen volumio[10125]: info: CorePlayQueue::getTrack 0 Aug 29 17:15:54 kitchen volumio[10125]: info: CoreStateMachine::startPlaybackTimer Aug 29 17:15:54 kitchen volumio[10125]: info: CorePlayQueue::getTrack 0 Aug 29 17:15:54 kitchen volumio[10125]: info: [1788016554815] ControllerSpotify::clearAddPlayTrack Aug 29 17:15:54 kitchen volumio[10125]: info: Sending Spotify command with payload to local API: /player/play Aug 29 17:15:54 kitchen volumio[10125]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:54 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:54 kitchen volumio[10125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:15:57 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 29 17:15:57 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:57 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:15:57 kitchen go-librespot[9954]: go-librespot daemon starting... Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=debug msg="app state loaded" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02: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]" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02: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]" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=info msg="zeroconf server listening on port 39543" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=debug msg="obtained new client token: AAGib9cW68BcTAHTUEIxtmvwrnn+FFG+bKklROGu962cAetufOsv4lQVizZqhhd2u4xG1tpSvPTwK1VDHef14rr1Own3MImPyXdybrw7Ztal6vHXmY7qA5lOiEmmrcAfevOySr4M/ohHJImsoVaqgDcp7PXy6h30U3RcctZb1uOaiWG3fDeARZy1RrGFPaF3vN1GvMH0cMCuo8MJru3SH3NGq6PW8UEKYEmDd/AxyfNS6yUVooPooj8=" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=debug msg="completed keyexchange" Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=debug msg="completed challenge" Aug 29 17:15:57 kitchen volumio[10125]: info: Initializing connection to go-librespot Websocket Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=debug msg="new websocket client" Aug 29 17:15:57 kitchen volumio[10125]: info: Connection to go-librespot Websocket established Aug 29 17:15:57 kitchen go-librespot[9955]: time="2026-08-29T17:15:57+02:00" level=info msg="authenticated AP" username="11*****17" Aug 29 17:15:58 kitchen go-librespot[9955]: time="2026-08-29T17:15:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 17:15:58 kitchen systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 17:15:58 kitchen volumio[10125]: info: Connection to go-librespot Websocket closed Aug 29 17:15:58 kitchen systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 17:16:00 kitchen volumio[10125]: info: Getting Spotify volume Aug 29 17:16:00 kitchen volumio[10125]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 17:16:00 kitchen volumio[10125]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 17:16:00 kitchen volumio[10125]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 29 17:16:00 kitchen volumio[10125]: errno: -111, Aug 29 17:16:00 kitchen volumio[10125]: code: 'ECONNREFUSED', Aug 29 17:16:00 kitchen volumio[10125]: syscall: 'connect', Aug 29 17:16:00 kitchen volumio[10125]: address: '127.0.0.1', Aug 29 17:16:00 kitchen volumio[10125]: port: 9879, Aug 29 17:16:00 kitchen volumio[10125]: response: undefined Aug 29 17:16:00 kitchen volumio[10125]: } Aug 29 17:16:00 kitchen volumio[10125]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 17:16:01 kitchen systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 29 17:16:01 kitchen systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:16:01 kitchen systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 17:16:01 kitchen go-librespot[9990]: go-librespot daemon starting... Aug 29 17:16:01 kitchen go-librespot[9991]: time="2026-08-29T17:16:01+02:00" level=info msg="running go-librespot 0.7.1" Aug 29 17:16:01 kitchen go-librespot[9991]: time="2026-08-29T17:16:01+02:00" level=debug msg="app state loaded" Aug 29 17:16:01 kitchen go-librespot[9991]: time="2026-08-29T17:16:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 17:16:01 kitchen sudo[10001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 17:15' Aug 29 17:16:01 kitchen sudo[10001]: 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"